java.lang.AbstractMethodError: com.mysql.jdbc.Connection.isValid(I)Z

BUG来源

根据https://spring.io/guides/gs/accessing-data-mysql/进行操作,

照抄教程中的:

spring.datasource.driver-class-name =com.mysql.jdbc.Driver

mvn package成功,IDEA运行JAR成功,但是在(git bash/ win10命令行)中通过java指令运行JAR失败。

可能的原因及解决办法

没有正确加载驱动类。

spring.datasource.driver-class-name =com.mysql.jdbc.Driver

修改为

spring.datasource.driver-class-name =com.mysql.cj.jdbc.Driver

依据是程序在测试阶段,以及成功执行JAR时日志中的相关提示和警告(WARN)。

BUG探究

发现执行mvn package -DskipTests时,数据库里没有表。

执行mvn package后,数据库里多了两个hibernate_sequence和user表

证明这两张表是在测试阶段生产的,测试阶段并没有报错,

但是等到执行java -jar target/accessingdatamysql-0.0.1-SNAPSHOT.jar时却报错误

经过实验证明,执行JAVA指令前,不管数据库里面有没表都报同样的错误,且执行JAVA指令的过程中,并不生成表

BUG的进一步探究

是什么导致测试阶段不报错,但是运行JAR时却报错?

精简版测试阶段日志:

[INFO] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
[INFO] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 49 ms. Found 1 JPA repository interfaces.
Loading class `com.mysql.jdbc.Driver'. This is deprecated. The new driver class is `com.mysql.cj.jdbc.Driver'. The driver is automatically registered via the SPI and manual loading of the driver class is generally unnecessary.
[INFO] o.hibernate.jpa.internal.util.LogHelper : HHH000204: Processing PersistenceUnitInfo [name: default]
[INFO] org.hibernate.Version : HHH000412: Hibernate ORM core version 5.6.5.Final
[INFO] o.hibernate.annotations.common.Version : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
[INFO] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...
[WARN] com.zaxxer.hikari.util.DriverDataSource : Registered driver with driverClassName=com.mysql.jdbc.Driver was not found, trying direct instantiation.
[INFO] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed.
[INFO] org.hibernate.dialect.Dialect : HHH000400: Using dialect: org.hibernate.dialect.MySQL57Dialect
[INFO] o.h.e.t.j.p.i.JtaPlatformInitiator : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
[INFO] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
[WARN] JpaBaseConfiguration$JpaWebConfiguration : spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning
[INFO] c.e.a.AccessingdatamysqlApplicationTests : Started AccessingdatamysqlApplicationTests in 5.115 seconds (JVM running for 6.501)

本想打印执行java -jar target/accessingdatamysql-0.0.1-SNAPSHOT.jar后的错误日志,但是接下来发生了一个让我非常意外的事情。

因为我本来是在WIN10环境下用Git Bash执行java -jar target/accessingdatamysql-0.0.1-SNAPSHOT.jar指令的,这样输出到控制台的日志没有高亮,不方便阅读

因此,为了更清楚地看错误日志,我用IntelliJ IDEA Community Edition 2021.3.1重新去跑这个JAR包,没想到竟然没有报任何错误。就成功执行了。

并且在执行之后MySQL里确实新创建了hibernate_sequence和user表,证明确实连上了数据库。

观察到IDEA是用下面这个指令跑的程序:

"C:\xxx\java.exe" -Dfile.encoding=GBK -jar D:\xxxx\accessingdatamysql\target\accessingdatamysql-0.0.1-SNAPSHOT.jar

因此推测之前之所以报错,很可能是文件的字符集问题,于是用上面的指令在Git Bash下又跑一次程序:

java -Dfile.encoding=GBK -jar target/accessingdatamysql-0.0.1-SNAPSHOT.jar 

没想还是报了原来的错误,看着冗长难以阅读的错误日志,我选择用WIN10原装命令行再去跑这个程序(以上为Git Bash的执行结果)。结果是无论是加-Dfile.encoding=GBK还是不加,都报了原来的错误。我一怒之下,在命令行下采用绝对路径执行,就是原原本本拷贝IDEA的指令:

"C:\Program Files\Java\jdk1.8.0_101\bin\java.exe" -Dfile.encoding=GBK -jar D:\xxxxxx\accessingdatamysql\target\accessingdatamysql-0.0.1-SNAPSHOT.jar

没想到执行成功了,而且数据库里确实多了两张表。

经过检查,本地JAVA指令确实对应"C:\Program Files\Java\jdk1.8.0_101\bin\java.exe"(环境变量一致、版本一致):

java -version
java version "1.8.0_101"
Java(TM) SE Runtime Environment (build 1.8.0_101-b13)
Java HotSpot(TM) 64-Bit Server VM (build 25.101-b13, mixed mode)

于是在好奇心的驱使下,我又用java指令+绝对路径执行:

java -Dfile.encoding=GBK -jar D:\xxx\accessingdatamysql\target\accessingdatamysql-0.0.1-SNAPSHOT.jar

结果还是报了原来的错误,再尝试:

"java.exe" -Dfile.encoding=GBK -jar D:\xxx\accessingdatamysql\target\accessingdatamysql-0.0.1-SNAPSHOT.jar

仍然报原来的错误。又一次用:

"C:\Program Files\Java\jdk1.8.0_101\bin\java.exe" -Dfile.encoding=GBK -jar D:\xxx\accessingdatamysql\target\accessingdatamysql-0.0.1-SNAPSHOT.jar

还是成功的。没有报任何错误,数据里也多出了两张表。我感到非常不可思议。又执行:

"C:\Program Files\Java\jdk1.8.0_101\bin\java.exe" -Dfile.encoding=GBK -jar accessingdatamysql-0.0.1-SNAPSHOT.jar

还是成功了。我继续执行:

"C:\Program Files\Java\jdk1.8.0_101\bin\java.exe" -jar accessingdatamysql-0.0.1-SNAPSHOT.jar

依然成功。

百思不得其解,我甚至重新配了一遍环境变量,也不能够解决问题。

至于通过"C:\Program Files\Java\jdk1.8.0_101\bin\java.exe""java.exe"执行程序的区别,网上也没有相关的资料。

回到错误日志

只好回到原来的思路,老老实实分析一下执行java -jar target/accessingdatamysql-0.0.1-SNAPSHOT.jar后的错误日志:

[INFO].s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
[INFO].s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 57 ms. Found 1 JPA repository interfaces.
[INFO]省略嵌入式汤姆猫的初始化过程
[INFO]w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 3521 ms
[INFO]o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
[INFO]org.hibernate.Version                    : HHH000412: Hibernate ORM core version 5.6.5.Final
[INFO]o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
[INFO]com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
[INFO]com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Driver does not support get/set network timeout for connections. (com.mysql.jdbc.Connection.getNetworkTimeout()I)
[ERROR]com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to execute isValid() for connection, configure connection test query (com.mysql.jdbc.Connection.isValid(I)Z).
[WARN]ConfigServletWebServerApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'entityManagerFactory' defined in class path resource [org/springframework/boot/autoconfigure/orm/jpa/HibernateJpaConfiguration.class]: Invocation of init method failed; nested exception is java.lang.AbstractMethodError: com.mysql.jdbc.Connection.isValid(I)Z
[INFO]o.apache.catalina.core.StandardService   : Stopping service [Tomcat]
[INFO]ConditionEvaluationReportLoggingListener :

Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled.
08.472[ERROR]o.s.boot.SpringApplication               : Application run failed

org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'entityManagerFactory' defined in class path resource [org/springframework/boot/autoconfigure/orm/jpa/HibernateJpaConfiguration.class]: Invocation of init method failed; nested exception is java.lang.AbstractMethodError: com.mysql.jdbc.Connection.isValid(I)Z
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1804) ~[spring-beans-5.3.16.jar!/:5.3.16]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:620) ~[spring-beans-5.3.16.jar!/:5.3.16]
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542) ~[spring-beans-5.3.16.jar!/:5.3.16]
此处省略20多行
Caused by: java.lang.AbstractMethodError: com.mysql.jdbc.Connection.isValid(I)Z
        at com.zaxxer.hikari.pool.PoolBase.checkValidationSupport(PoolBase.java:464) ~[HikariCP-4.0.3.jar!/:na]
        at com.zaxxer.hikari.pool.PoolBase.checkDriverSupport(PoolBase.java:447) ~[HikariCP-4.0.3.jar!/:na]
        at com.zaxxer.hikari.pool.PoolBase.setupConnection(PoolBase.java:416) ~[HikariCP-4.0.3.jar!/:na]
        at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:369) ~[HikariCP-4.0.3.jar!/:na]
        at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:206) ~[HikariCP-4.0.3.jar!/:na]
        at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:476) ~[HikariCP-4.0.3.jar!/:na]
此处省略20多行
        ... 24 common frames omitted

也就是说,调用抽象方法com.mysql.jdbc.Connection.isValid(I)Z发生了错误。

根据正确执行的日志中的:Loading class `com.mysql.jdbc.Driver'. This is deprecated. The new driver class is `com.mysql.cj.jdbc.Driver'. The driver is automatically registered via the SPI and manual loading of the driver class is generally unnecessary.

推测是由于某种原因,在用java指令执行JAR时没有正确地加载驱动类

因此将

spring.datasource.driver-class-name =com.mysql.jdbc.Driver

修改为

spring.datasource.driver-class-name =com.mysql.cj.jdbc.Driver

保存之后通过mvn clean以及mvn package -DskipTests重新编译打包程序,并通过IDEA运行打包后的程序。正常运行且不报Loading class `com.mysql.jdbc.Driver'. This is deprecated. The new driver class is `com.mysql.cj.jdbc.Driver'. The driver is automatically registered via the SPI and manual loading of the driver class is generally unnecessary.

通过mvn clean package再执行一遍,测试阶段日志也不再报[WARN] com.zaxxer.hikari.util.DriverDataSource : Registered driver with driverClassName=com.mysql.jdbc.Driver was not found, trying direct instantiation.

清空数据库里新创建的两张表,cd到target文件夹下执行

java -jar accessingdatamysql-0.0.1-SNAPSHOT.jar

这次终于没问题了。

posted @ 2022-03-13 17:02  xkfx  阅读(1429)  评论(0编辑  收藏  举报