一次在 classpath 使用通配符导致的偶发问题排查与建议

wuweijie@apache.org

于 2023-02-03 23:22:08 发布

阅读量533

点赞数 2

分类专栏： Java 踩坑文章标签： java jvm

本文链接：https://blog.csdn.net/wu_weijie/article/details/128676834

版权

Java 同时被 2 个专栏收录

24 篇文章 0 订阅

订阅专栏

踩坑

15 篇文章 0 订阅

订阅专栏

说起 Classpath，使用 Java 的同学应该都不会陌生。不过，目前的项目基本都会使用 Maven 等构建工具管理，开发过程中也会使用高度智能化的 IDE，在日常使用中直接涉及 Classpath 操作可能不多。前段时间遇到一个跟 Classpath 相关的偶发问题，本文记录这个问题的排查过程与建议。

结论与建议

问题原因

两个包含同名类的 JAR 包在同一个目录下（类同名但行为不一致）；
Proxy 启动脚本 classpath 使用了通配符，不同环境下 lib 下面的 jar 加载顺序存在差异；
在不同环境、时刻启动 ShardingSphere-Proxy，实际使用的 JAR 存在不确定性。

建议

开发者在为项目引入依赖的时候，需要对依赖有一个基本的了解，避免同时引入两个不同坐标但同源的依赖（例如本文的 MySQL Connector/J 和 AWS JDBC Driver for MySQL）。

问题现象

前段时间，在我个人仓库运行 ShardingSphere-Proxy 集成测试的时候发现，有个 MySQL Proxy 集成测试用例失败了，而且重试了 2 次仍然失败。
但是，第二天点了一下重试后，测试居然过了，下图的 Latest attempt #4 虽然显示是失败，但这个之前失败的 case 已经通过了。
在这里插入图片描述

回想一下，也跟踪了一下代码提交记录，最近并没有修改 MySQL 协议或 MySQL 相关的逻辑。

报错信息很明显，测试用例原本期望是一个 boolean true，实际上却拿到了一个 1。

Error:  Failures: 
Error:  org.apache.shardingsphere.test.e2e.engine.dql.GeneralDQLE2EIT.assertExecuteQuery[proxy: shadow -> MySQL -> Literal -> SELECT order_id, user_id, order_name, type_char, type_boolean, type_smallint, type_enum, type_decimal, type_date, type_time, type_timestamp FROM t_shadow WHERE user_id = ?]
Error:    Run 1: GeneralDQLE2EIT.assertExecuteQuery:58->assertExecuteQueryForStatement:71->BaseDQLE2EIT.assertResultSet:78->BaseDQLE2EIT.assertRows:93->BaseDQLE2EIT.assertRow:111 
Expected: is "true"
     but: was "1"
Error:    Run 2: GeneralDQLE2EIT.assertExecuteQuery:58->assertExecuteQueryForStatement:71->BaseDQLE2EIT.assertResultSet:78->BaseDQLE2EIT.assertRows:93->BaseDQLE2EIT.assertRow:111 
Expected: is "true"
     but: was "1"
[INFO] 
Error:  org.apache.shardingsphere.test.e2e.engine.dql.GeneralDQLE2EIT.assertExecuteQuery[proxy: shadow -> MySQL -> Placeholder -> SELECT order_id, user_id, order_name, type_char, type_boolean, type_smallint, type_enum, type_decimal, type_date, type_time, type_timestamp FROM t_shadow WHERE user_id = ?]
Error:    Run 1: GeneralDQLE2EIT.assertExecuteQuery:60->assertExecuteQueryForPreparedStatement:86->BaseDQLE2EIT.assertResultSet:78->BaseDQLE2EIT.assertRows:93->BaseDQLE2EIT.assertRow:111 
Expected: is "true"
     but: was "1"
Error:    Run 2: GeneralDQLE2EIT.assertExecuteQuery:60->assertExecuteQueryForPreparedStatement:86->BaseDQLE2EIT.assertResultSet:78->BaseDQLE2EIT.assertRows:93->BaseDQLE2EIT.assertRow:111 
Expected: is "true"
     but: was "1"
[INFO] 
Error:  org.apache.shardingsphere.test.e2e.engine.dql.GeneralDQLE2EIT.assertExecute[proxy: shadow -> MySQL -> Literal -> SELECT order_id, user_id, order_name, type_char, type_boolean, type_smallint, type_enum, type_decimal, type_date, type_time, type_timestamp FROM t_shadow WHERE user_id = ?]
Error:    Run 1: GeneralDQLE2EIT.assertExecute:97->assertExecuteForStatement:112->BaseDQLE2EIT.assertResultSet:78->BaseDQLE2EIT.assertRows:93->BaseDQLE2EIT.assertRow:111 
Expected: is "true"
     but: was "1"
Error:    Run 2: GeneralDQLE2EIT.assertExecute:97->assertExecuteForStatement:112->BaseDQLE2EIT.assertResultSet:78->BaseDQLE2EIT.assertRows:93->BaseDQLE2EIT.assertRow:111 
Expected: is "true"
     but: was "1"
[INFO] 
Error:  org.apache.shardingsphere.test.e2e.engine.dql.GeneralDQLE2EIT.assertExecute[proxy: shadow -> MySQL -> Placeholder -> SELECT order_id, user_id, order_name, type_char, type_boolean, type_smallint, type_enum, type_decimal, type_date, type_time, type_timestamp FROM t_shadow WHERE user_id = ?]
Error:    Run 1: GeneralDQLE2EIT.assertExecute:99->assertExecuteForPreparedStatement:129->BaseDQLE2EIT.assertResultSet:78->BaseDQLE2EIT.assertRows:93->BaseDQLE2EIT.assertRow:111 
Expected: is "true"
     but: was "1"
Error:    Run 2: GeneralDQLE2EIT.assertExecute:99->assertExecuteForPreparedStatement:129->BaseDQLE2EIT.assertResultSet:78->BaseDQLE2EIT.assertRows:93->BaseDQLE2EIT.assertRow:111 
Expected: is "true"
     but: was "1"

排查过程

本地运行集成测试，无法复现

问题在 GitHub Actions 上连续失败了 3 次，那本地是否有可能快速复现？

将 GitHub Actions 上的 Proxy 测试镜像导入到本地，使用相同的命令运行测试：

./mvnw -nsu -B install -f test/e2e/suite/pom.xml -Dspotless.apply.skip=true -Dit.cluster.env.type=DOCKER -Dit.cluster.adapters=proxy -Dit.run.modes=Cluster -Dit.cluster.databases=MySQL -Dit.scenarios=shadow

本地运行的时候有个小插曲。

集成测试使用的 MySQL server 镜像为：mysql/mysql-server:5.7

在运行测试的时候发现，测试启动的 MySQL server 版本存在一定差异。GitHub Actions 实际运行的 MySQL server 版本为：5.7.40-1.2.10-server

[INFO ] 2023-01-12 02:21:42.869 [docker-java-stream--198238272] 🐳 [mysql/mysql-server:5.7] - Pull complete. 8 layers, pulled in 13s (downloaded 150 MB at 11 MB/s)
[INFO ] 2023-01-12 02:21:42.876 [main] 🐳 [mysql/mysql-server:5.7] - Creating container for image: mysql/mysql-server:5.7
[INFO ] 2023-01-12 02:21:43.134 [main] 🐳 [mysql/mysql-server:5.7] - Container mysql/mysql-server:5.7 is starting: 78e6a4132439b0383add9d9fc8306690a94a31d421cdeb559801c81cec223353
[INFO ] 2023-01-12 02:21:43.501 [docker-java-stream-1124194819] shadow:mysql - STDOUT: [Entrypoint] MySQL Docker Image 5.7.40-1.2.10-server

但是本地运行集成测试拉下来的 MySQL server 实际是：5.7.36-1.2.6-server

[INFO ] 2023-01-13 13:24:41.494 [docker-java-stream-1264158127] 🐳 [mysql/mysql-server:5.7] - Pull complete. 8 layers, pulled in 31s (downloaded 127 MB at 4 MB/s)
[INFO ] 2023-01-13 13:24:41.501 [main] 🐳 [mysql/mysql-server:5.7] - Creating container for image: mysql/mysql-server:5.7
[INFO ] 2023-01-13 13:24:41.738 [main] 🐳 [mysql/mysql-server:5.7] - Container mysql/mysql-server:5.7 is starting: b1909b805a9db021633b928242f605307533b09b6a1dee5487b481b770405776
[INFO ] 2023-01-13 13:24:42.111 [docker-java-stream--726063482] shadow:mysql - STDOUT: [Entrypoint] MySQL Docker Image 5.7.36-1.2.6-server

本地删除镜像后通过命令重新 pull，结果还是一样的，后来发现是本地使用了阿某云的镜像加速服务。删除 Registry 后，重新 pull 镜像的结果与 GitHub Actions 一致。

在本地运行了多次集成测试，全部通过，未能复现问题。

调整测试框架 MySQL Connector/J 版本为 8.0.22

考虑 MySQL 5.7 和 8.0 对 boolean 的支持存在差异，调整测试框架 MySQL Connector/J 版本为 8.0.22。
在这里插入图片描述
调整后，集成测试报错，但是报错的是日期时间相关的断言，与本问题无关，不继续展开调查。
DQL 用例均通过，因此可以排除是 MySQL 客户端版本问题。

调整 Proxy 集成测试镜像依赖

查看镜像文件的时候发现：集成测试镜像依赖中还有 aws-mysql-jdbc 依赖。之前检查过 ShardingSphere 的 MySQL 协议等相关代码没有发生变动，但是没有想起代码中增加过 AWS 的 MySQL JDBC 驱动。

移除原版 MySQL 驱动

有没有可能是 Proxy 实际用了 aws-mysql-jdbc 驱动连接的 MySQL？

FROM 9ea895f0bb57
RUN rm /opt/shardingsphere-proxy/lib/mysql-connector-java-5.1.47.jar

移除后，Proxy 由于无法加载 MySQL 驱动 XA 相关类，无法正常启动。

查看 aws-mysql-jdbc 源码发现，AWS 驱动是基于 MySQL Connector/J 8.0.x 开发的，也持续在同步上游 MySQL Connector/J 8.x 的代码，因此 aws-mysql-jdbc 驱动相当于是个 MySQL 8.x 的驱动。

将 Proxy 集成测试镜像调整为 MySQL Connector/J 8.0.22

FROM 9ea895f0bb57
RUN rm /opt/shardingsphere-proxy/lib/mysql-connector-java-5.1.47.jar /opt/shardingsphere-proxy/lib/aws-mysql-jdbc-1.1.2.jar
COPY mysql-connector-java-8.0.22.jar /opt/shardingsphere-proxy/lib/mysql-connector-java-8.0.22.jar

测试报错，问题复现

[ERROR] org.apache.shardingsphere.test.e2e.engine.dql.GeneralDQLE2EIT.assertExecute[proxy: shadow -> MySQL -> Literal -> SELECT order_id, user_id, order_name, type_char, type_boolean, type_smallint, type_enum, type_decimal, type_date, type_time, type_timestamp FROM t_shadow WHERE user_id = ?]
[ERROR]   Run 1: GeneralDQLE2EIT.assertExecute:97->assertExecuteForStatement:112->BaseDQLE2EIT.assertResultSet:78->BaseDQLE2EIT.assertRows:93->BaseDQLE2EIT.assertRow:111 
Expected: is "true"
     but: was "1"
[ERROR]   Run 2: GeneralDQLE2EIT.assertExecute:97->assertExecuteForStatement:112->BaseDQLE2EIT.assertResultSet:78->BaseDQLE2EIT.assertRows:93->BaseDQLE2EIT.assertRow:111 
Expected: is "true"
     but: was "1"
[INFO] 
[ERROR] org.apache.shardingsphere.test.e2e.engine.dql.GeneralDQLE2EIT.assertExecute[proxy: shadow -> MySQL -> Placeholder -> SELECT order_id, user_id, order_name, type_char, type_boolean, type_smallint, type_enum, type_decimal, type_date, type_time, type_timestamp FROM t_shadow WHERE user_id = ?]
[ERROR]   Run 1: GeneralDQLE2EIT.assertExecute:99->assertExecuteForPreparedStatement:129->BaseDQLE2EIT.assertResultSet:78->BaseDQLE2EIT.assertRows:93->BaseDQLE2EIT.assertRow:111 
Expected: is "true"
     but: was "1"
[ERROR]   Run 2: GeneralDQLE2EIT.assertExecute:99->assertExecuteForPreparedStatement:129->BaseDQLE2EIT.assertResultSet:78->BaseDQLE2EIT.assertRows:93->BaseDQLE2EIT.assertRow:111 
Expected: is "true"
     but: was "1"
[INFO] 
[ERROR] Tests run: 60, Failures: 4, Errors: 0, Skipped: 0
[INFO] 
[INFO] --- maven-failsafe-plugin:2.22.0:verify (integration-tests) @ shardingsphere-test-e2e-suite ---
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  50.246 s

说明该集成测试可能与 aws-mysql-jdbc 相关。

但如何证明？
能否不增减依赖的前提下复现问题？

调整 Proxy 集成测试镜像 classpath 顺序

Proxy 启动脚本 classpath 定义如下：

CLASS_PATH=.:${DEPLOY_DIR}/lib/*:${EXT_LIB}/*

由于 lib 目录使用的是通配符，可能在不同环境下，lib 内的 jar 会有不同的加载顺序。

将 aws-mysql-jdbc 顺序置于 mysql-connector-java 后

把 aws-mysql-jdbc JAR 移动到顺序靠后的 ext-lib

FROM 9ea895f0bb57
RUN mkdir /opt/shardingsphere-proxy/ext-lib && mv /opt/shardingsphere-proxy/lib/aws-mysql-jdbc-1.1.2.jar /opt/shardingsphere-proxy/ext-lib/

测试通过，问题未复现

[INFO] Tests run: 64, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 40.525 s - in JUnit Vintage
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  50.701 s

将 mysql-connector-java 顺序置于 aws-mysql-jdbc 后

把 mysql-connector-java JAR 移动到顺序靠后的 ext-lib

FROM 9ea895f0bb57
RUN mkdir /opt/shardingsphere-proxy/ext-lib && mv /opt/shardingsphere-proxy/lib/mysql-connector-java-5.1.47.jar /opt/shardingsphere-proxy/ext-lib/

测试报错，问题复现

移除 aws-mysql-jdbc

FROM 9ea895f0bb57
RUN mkdir /opt/shardingsphere-proxy/ext-lib && mv /opt/shardingsphere-proxy/lib/mysql-connector-java-5.1.47.jar /opt/shardingsphere-proxy/ext-lib/ && rm /opt/shardingsphere-proxy/lib/aws-mysql-jdbc-1.1.2.jar

测试通过，下结论

所以该问题结论：因为依赖冲突导致的，加上 classpath 通配符导致的 JAR 顺序无法保证，导致 ShardingSphere-Proxy 在不同时刻使用了不同的 JAR 引发的问题。
通过调试 Proxy 进程可以进一步证实该问题，此处不再赘述。

关于 classpath

classpath 案例与文档解读

对于依赖相关问题，我想起之前遇到过一个案例：
classpath 的两个目录下有两个不同版本的 MySQL Connector/J，大致情形如下：

lib/mysql-connector-java-8.0.22.jar
ext-lib/mysql-connector-java-8.0.27.jar

而 classpath 的写法为：

java -cp lib/*:ext-lib/*

最终，ShardingSphere-Proxy 实际使用的都是 lib 目录下 8.0.22 版本的驱动。

关于 classpath 可以参考文档：

https://docs.oracle.com/javase/7/docs/technotes/tools/windows/classpath.html

其中有一段：

The order in which the JAR files in a directory are enumerated in the expanded class path is not specified and may vary from platform to platform and even from moment to moment on the same machine. A well-constructed application should not depend upon any particular order. If a specific order is required then the JAR files can be enumerated explicitly in the class path.

意思大致就是：一个通配符目录下的 JAR 加载顺序无法得到保证。

因此，如果一个目录下有两个 JAR 并且 JAR 包含了相同的类，在不同环境或同一环境的不同时刻启动程序，实际使用的 JAR 是无法保证的。

classpath 通配符模拟实验

创建一个 Dependency.java ，将 println 的内容改为 version A 打一个 JAR dependency-a.jar，再将 println 的内容改为 version B 打一个 JAR dependency-b.jar

λ ~/test_cp/ tree
.
├── Main.java
└── lib
    ├── Dependency.java
    ├── dependency-a.jar
    └── dependency-b.jar

1 directory, 4 files

λ ~/test_cp/ cat Main.java lib/Dependency.java 

public class Main {

    public static void main(String[] args) {
        new Dependency().getVersion();
    }
}

public class Dependency {

    public void getVersion() {
        System.out.println("I'm version B");
    }
}

使用通配符指定 classpath 目录，启动程序。

λ ~/test_cp/ java -cp 'lib/dependency-a.jar' Main.java
I'm version A

λ ~/test_cp/ java -cp 'lib/dependency-b.jar' Main.java
I'm version B

λ ~/test_cp/ java -cp 'lib/*' Main.java

使用通配符结果如何？
运行结果为 B。
在这里插入图片描述

多运行几次命令，用 Docker 运行，结果都是一样的。
在这里插入图片描述

等第二天再跑一下看结果会不会变。

wuweijie@apache.org

关注

2
点赞
踩
1

收藏

觉得还不错? 一键收藏
打赏
0
评论
一次在 classpath 使用通配符导致的偶发问题排查与建议

说起 Classpath，使用 Java 的同学应该都不会陌生。不过，目前的项目基本都会使用 Maven 等构建工具管理，开发过程中也会使用高度智能化的 IDE，在日常使用中直接涉及 Classpath 操作可能不多。前段时间遇到一个跟 Classpath 相关的偶发问题，本文记录这个问题的排查过程与建议。
复制链接

扫一扫