说起 Classpath,使用 Java 的同学应该都不会陌生。不过,目前的项目基本都会使用 Maven 等构建工具管理,开发过程中也会使用高度智能化的 IDE,在日常使用中直接涉及 Classpath 操作可能不多。前段时间遇到一个跟 Classpath 相关的偶发问题,本文记录这个问题的排查过程与建议。
文章目录
- 结论与建议
- 问题原因
- 建议
- 问题现象
- 排查过程
- 本地运行集成测试,无法复现
- 调整测试框架 MySQL Connector/J 版本为 8.0.22
- 调整 Proxy 集成测试镜像依赖
- 移除原版 MySQL 驱动
- 将 Proxy 集成测试镜像调整为 MySQL Connector/J 8.0.22
- 测试报错,问题复现
- 调整 Proxy 集成测试镜像 classpath 顺序
- 将 aws-mysql-jdbc 顺序置于 mysql-connector-java 后
- 测试通过,问题未复现
- 将 mysql-connector-java 顺序置于 aws-mysql-jdbc 后
- 测试报错,问题复现
- 移除 aws-mysql-jdbc
- 测试通过,下结论
- 关于 classpath
- 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 的驱动。
相关源码:https://github.com/awslabs/aws-mysql-jdbc/blob/main/src/main/user-impl/java/com/mysql/cj/jdbc/Driver.java
将 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 运行,结果都是一样的。
等第二天再跑一下看结果会不会变。