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原裝命令列再去跑這個程式。結果是無論是加-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.

推測是沒有正確的載入驅動類。

因此將

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

這次終於沒問題了。