1、问题背景
我们项目中引入了sharding-jdbc,本机运行、开发环境运行、测试环境运行都没有问题,结果到了预发布环境发生了一个异常:
Cannot support database type 'MySQL' at org.apache.shardingsphere.sql.parser.core.parser.SQLParserFactory.newInstance(SQLParserFactory.java:55)
at org.apache.shardingsphere.sql.parser.core.parser.SQLParserExecutor.towPhaseParse(SQLParserExecutor.java:55)
at org.apache.shardingsphere.sql.parser.core.parser.SQLParserExecutor.execute(SQLParserExecutor.java:47)
at org.apache.shardingsphere.sql.parser.SQLParserEngine.parse0(SQLParserEngine.java:79)
at org.apache.shardingsphere.sql.parser.SQLParserEngine.parse(SQLParserEngine.java:61)
at org.apache.shardingsphere.underlying.route.DataNodeRouter.createRouteContext(DataNodeRouter.java:97)
at org.apache.shardingsphere.underlying.route.DataNodeRouter.executeRoute(DataNodeRouter.java:89)
at org.apache.shardingsphere.underlying.route.DataNodeRouter.route(DataNodeRouter.java:76)
at org.apache.shardingsphere.underlying.pluggble.prepare.PreparedQueryPrepareEngine.route(PreparedQueryPrepareEngine.java:54)
而我们除了本机环境各人使用上有些差异外,开发环境运行、测试环境运行和预发布环境上只有MySQL服务端版本是不同的,虽然是报错上看和MySQL服务端并没有直接关系,但我们还是在开发环境还原了预发布环境的MySQL服务端版本,还原之后开发环境并没有复现问题。
这就非常诡异了。也给我们解决带来了一定的技术挑战:不能通过本地调试或者加JVM参数来做进一步验证。
以下就是我们的排查过程。
2、源码分析
既然有明确的报错日志,首先要进行代码分析:
SQLParserFactory.newInstance(SQLParserFactory.java:55)
跟进这一行报错的源码:
public static SQLParser newInstance(final String databaseTypeName, final String sql) {
for (SQLParserConfiguration each : NewInstanceServiceLoader.newServiceInstances(SQLParserConfiguration.class)) {
if (each.getDatabaseTypeName().equals(databaseTypeName)) {
return createSQLParser(sql, each);
}
}
throw new UnsupportedOperationException(String.format("Cannot support database type '%s'", databaseTypeName));
}
第7行抛出了日志中的异常。这说明问题就发生在2、3、4这三行中的一行。
究竟是哪一行呢?本地可以调试的话很简单,Debug跟踪一下,但是预发布环境不能Debug呀!当然其实有些公司网是通的,可以做远程Debug,更多的是一个规范的问题。
在不能Debug的前提下,我把这三行代码拷贝出来,分步打日志,再放到预发布环境运行:
try{
log.warn("ShardingDebug test=1==============================begin");
for (SQLParserConfiguration each : NewInstanceServiceLoader.newServiceInstances(SQLParserConfiguration.class)) {
log.warn("ShardingDebug test=2==============================each:{}", each);
if (each.getDatabaseTypeName().equals("MySQL")) {
log.warn("ShardingDebug test=3==============================equals:{}", each);
CodePointCharStream codePointCharStream = CharStreams.fromString("select version()");
log.warn("ShardingDebug test=4==============================codePointCharStream:{}", codePointCharStream);
// 这次存在
Lexer lexer = null;
try {
log.warn("ShardingDebug test=5.0==============================MySQLLexer:{}", each.getLexerClass().getName());
log.warn("ShardingDebug test=5.1==============================MySQLLexer:{}", each.getLexerClass().getConstructor(CharStream.class).getName());
SQLLexer sqlLexer = each.getLexerClass().getConstructor(CharStream.class).newInstance(codePointCharStream);
log.warn("ShardingDebug test=5.2==============================sqlLexer:{}, isInstance:{}", sqlLexer, sqlLexer instanceof Lexer);
lexer = (Lexer) each.getLexerClass().getConstructor(CharStream.class).newInstance(codePointCharStream);
log.warn("ShardingDebug test=5==============================lexer:{}", lexer);
} catch (InstantiationException e) {
log.error("ShardingDebug test=6==============================lexer:{}", lexer, e);
} catch (IllegalAccessException e) {
log.error("ShardingDebug test=7==============================lexer:{}", lexer, e);
} catch (InvocationTargetException e) {
log.error("ShardingDebug test=8==============================lexer:{}", lexer, e);
} catch (NoSuchMethodException e) {
log.error("ShardingDebug test=9==============================lexer:{}", lexer, e);
}
CommonTokenStream lexerCommonTokenStream = new CommonTokenStream(lexer);
log.warn("ShardingDebug test=10==============================lexerCommonTokenStream:{}", lexerCommonTokenStream);
SQLParser sqlParser = null;
try {
log.warn("ShardingDebug test=11.0==============================sqlParser:{}", each.getParserClass());
log.warn("ShardingDebug test=11.1==============================sqlParser:{}", each.getParserClass().getConstructor(TokenStream.class));
sqlParser = each.getParserClass().getConstructor(TokenStream.class).newInstance(lexerCommonTokenStream);
log.warn("ShardingDebug test=11==============================sqlParser:{}", sqlParser);
} catch (InstantiationException e) {
log.warn("ShardingDebug test=12==============================sqlParser:{}", sqlParser, e);
} catch (IllegalAccessException e) {
log.warn("ShardingDebug test=13==============================sqlParser:{}", sqlParser, e);
} catch (InvocationTargetException e) {
log.warn("ShardingDebug test=14==============================sqlParser:{}", sqlParser, e);
} catch (NoSuchMethodException e) {
log.warn("ShardingDebug test=15==============================sqlParser:{}", sqlParser, e);
}
break;
}
}
} catch (Exception ex) {
log.error("ShardDebugJob failed", ex);
}
}
我把这三行代码拆解的非常细,希望尽量减少发布,排查出问题的原因。
结果日志只打印了第一行,剩下的都没打印。说明没有进入for循环。也就说明了。
NewInstanceServiceLoader.newServiceInstances(SQLParserConfiguration.class)
没有加载到东西。再看这一行的源码:
public static Collection newServiceInstances(final Class service) {
Collection result = new LinkedList();
if (null == SERVICE_MAP.get(service)) {
return result;
}
for (Class each : SERVICE_MAP.get(service)) {
result.add((T) each.newInstance());
}
return result;
}
这说明SERVICE_MAP里没有对应的实现类。再看SERVICE_MAP赋值的源码:
public static void register(final Class service) {
for (T each : ServiceLoader.load(service)) {
registerServiceClass(service, each);
}
}
private static void registerServiceClass(final Class service, final T instance) {
Collection mySQLParserConfiguration = Thread.currentThread().getContextClassLoader().loadClass(MySQLParserConfiguration.class.getName());
log.info("ShardingDebug test=0.0==============================loadClass:{}", mySQLParserConfiguration);
结果正常打印了实现类的全限定名。
这里为什么我会想到Thread.currentThread().getContextClassLoader()这个类加载器呢?很简单。这个类加载器就是ServiceLoader.load源码里使用的类加载器。
@CallerSensitive
public static ServiceLoader load(Class service) {
ClassLoader cl = Thread.currentThread().getContextClassLoader();
return new ServiceLoader(Reflection.getCallerClass(), service, cl);
}
4、问题解决
到这里,解决方案也呼之欲出:既然是可以加载到的,那应该就是没有在注册服务代码执行前加载。手动让类加载在注册服务前运行即可。
Class mySQLParserConfiguration = Thread.currentThread().getContextClassLoader().loadClass(MySQLParserConfiguration.class.getName());
log.info("ShardingDebug test=0.0==============================loadClass:{}", mySQLParserConfiguration);
try {
NewInstanceServiceLoader.register(SQLParserConfiguration.class);
} catch (Throwable e) {
log.error("ShardingDebug test=0.011==============================register", e);
}
先执行这个,再执行最初的:
NewInstanceServiceLoader.newServiceInstances(SQLParserConfiguration.class)
就可以加载到对应的实例了。
4、分析总结
这次问题出现在sharding-jdbc的SQL解析阶段,可以通过源码上下文看到问题发生在与MySQL服务端交互之前,可排除受服务端的影响。并且可以确定问题发生在JVM内部。
可通过ServiceLoader.load(service)确定是使用了Java的SPI机制时发生问题。SPI的本质是通过META-INF/services目录下对应接口的文件找到实现类。
验证实现类可被JVM正常加载我使用了与源码相同的类加载器并发布到预发布环境进行验证。因为不同类加载器有不同的使用条件。比如:
ClassLoader.getSystemClassLoader()
在本机会正常运行,但是服务器上会因为运行的是打好的 jar 包,路径发生变化,服务器上运行报「找不到类」异常。
整个排查过程也有一些怎样搜索答案的思考,比如只是根据最初的异常来搜索,发现网上搜的都不是本质问题。后来虽然我用更接近本质的问题:
「找不到spi的实现类怎么解决」也没找到正确的答案,但是问题是更接近真相的。