spring-native icon indicating copy to clipboard operation
spring-native copied to clipboard

Add PerConnectionLRUFactory for MySQL JDBC driver

Open jbiancot opened this issue 1 year ago • 5 comments

Hi folks,

I am having some issues when my Spring Boot app when it starts, and it tries to use the Hikari connection pool. If I run the app using java -jar ... it works fine, but running the nativeBuild it throws a nasty error, I have no idea what to do with it.

I am building the project using my Mac Intel "macOS Monterey v12.5", using:

java -version
openjdk version "17.0.4" 2022-07-19
OpenJDK Runtime Environment GraalVM CE 22.2.0 (build 17.0.4+8-jvmci-22.2-b06)
OpenJDK 64-Bit Server VM GraalVM CE 22.2.0 (build 17.0.4+8-jvmci-22.2-b06, mixed mode, sharing)

gradle --version
------------------------------------------------------------
Gradle 7.5.1
------------------------------------------------------------

Build time:   2022-08-05 21:17:56 UTC
Revision:     d1daa0cbf1a0103000b71484e1dbfe096e095918

Kotlin:       1.6.21
Groovy:       3.0.10
Ant:          Apache Ant(TM) version 1.10.11 compiled on July 10 2021
JVM:          17.0.4 (GraalVM Community 17.0.4+8-jvmci-22.2-b06)
OS:           Mac OS X 12.5 x86_64

I have attached a file, which is the project on ZIP NativoProject.zip format. I have attached a file, which is the build and run of the project using JVM. I have attached a file, which is the build of native code I have attached a file, which is the run of the native code and the error.

Beware, I am using a basic MySQL 5.7.x server to connect, there is no need for tables.

You can create a basic MySQL database, be sure you change the application.properties file to have the correct, host "IP", the database name, and the credentials.

The error happens before it establishes a connection to the database server, meaning, if the credentials are valid or invalid, etc, it won't reach that stage, yet. it will throw the error first.

CREATE DATABASE `testing` /*!40100 DEFAULT CHARACTER SET utf8mb4 COLLATE utf8mb4_unicode_ci */

Here the files:

Build_and_run_for_JVM.txt Error_when_running_native.txt Build_for_native.txt

jbiancot avatar Aug 08 '22 00:08 jbiancot

Hi! Could you please try copying these files into your src/main/resources/META-INF/native-image folder and try again?

mhalbritter avatar Aug 08 '22 12:08 mhalbritter

Hi,

I did, and still getting the errors, please check the output. I have attached a file with the same content.

[Issues_August_8.txt](https://github.com/spring-projects-experimental/spring-native/files/9284923/Issues_August_8.txt)

./gradlew nativeBuild                                                       
Starting a Gradle Daemon (subsequent builds will be faster)

> Configure project :
[native-image-plugin] Instrumenting task with the native-image-agent: aotTest
[native-image-plugin] Instrumenting task with the native-image-agent: generateAot
[native-image-plugin] Instrumenting task with the native-image-agent: generateTestAot
[native-image-plugin] Instrumenting task with the native-image-agent: test

> Task :generateAot
Execution optimizations have been disabled for task ':generateAot' to ensure correctness due to the following reasons:
  - Additional action of task ':generateAot' was implemented by the Java lambda 'org.springframework.aot.gradle.SpringAotGradlePlugin$$Lambda$809/0x00000008012f19a8'. Reason: Using Java lambdas is not supported as task inputs. Please refer to https://docs.gradle.org/7.5/userguide/validation_problems.html#implementation_unknown for more details about this problem.
2022-08-08 22:32:52.302  INFO 1838 --- [           main] o.s.a.build.ContextBootstrapContributor  : Detected application class: net.yisu.august.Nativo.NativoApplication
2022-08-08 22:32:52.307  INFO 1838 --- [           main] o.s.a.build.ContextBootstrapContributor  : Processing application context
2022-08-08 22:32:55.379  INFO 1838 --- [           main] o.s.a.build.ContextBootstrapContributor  : Processed 166 bean definitions in 3069ms
2022-08-08 22:32:55.716  INFO 1838 --- [           main] o.s.nativex.support.SpringAnalyzer       : Spring Native operating mode: native

> Task :compileAotMainJava
warning: unknown enum constant When.MAYBE
  reason: class file for javax.annotation.meta.When not found
/Users/jbianco/Downloads/Nativo/build/generated/runtimeSources/aotMain/org/springframework/boot/jdbc/_FactoryProvider.java:4: warning: [deprecation] AbstractDataSourceInitializerDatabaseInitializerDetector in org.springframework.boot.jdbc has been deprecated
  public static AbstractDataSourceInitializerDatabaseInitializerDetector abstractDataSourceInitializerDatabaseInitializerDetector(
                ^
/Users/jbianco/Downloads/Nativo/build/generated/runtimeSources/aotMain/org/springframework/boot/jdbc/_FactoryProvider.java:6: warning: [deprecation] AbstractDataSourceInitializerDatabaseInitializerDetector in org.springframework.boot.jdbc has been deprecated
    return new AbstractDataSourceInitializerDatabaseInitializerDetector();
               ^
/Users/jbianco/Downloads/Nativo/build/generated/runtimeSources/aotMain/org/springframework/aot/StaticSpringFactories.java:26: warning: [unchecked] unchecked conversion
  public static MultiValueMap<Class, Supplier<Object>> factories = new LinkedMultiValueMap();
                                                                   ^
  required: MultiValueMap<Class,Supplier<Object>>
  found:    LinkedMultiValueMap
/Users/jbianco/Downloads/Nativo/build/generated/runtimeSources/aotMain/org/springframework/aot/StaticSpringFactories.java:28: warning: [unchecked] unchecked conversion
  public static MultiValueMap<Class, String> names = new LinkedMultiValueMap();
                                                     ^
  required: MultiValueMap<Class,String>
  found:    LinkedMultiValueMap
5 warnings

> Task :generateResourcesConfigFile
[native-image-plugin] Resources configuration written into /Users/jbianco/Downloads/Nativo/build/native/generated/generateResourcesConfigFile/resource-config.json

> Task :nativeCompile
[native-image-plugin] Toolchain detection is disabled, will use GraalVM from /Library/Java/JavaVirtualMachines/graalvm-ce-java17-22.2.0/Contents/Home.
[native-image-plugin] Using executable path: /Library/Java/JavaVirtualMachines/graalvm-ce-java17-22.2.0/Contents/Home/bin/native-image
Warning: Using a deprecated option --allow-incomplete-classpath from 'META-INF/native-image/org.springframework.aot/spring-aot/native-image.properties' in 'file:///Users/jbianco/Downloads/Nativo/build/libs/Nativo-1-aot.jar'. Allowing an incomplete classpath is now the default. Use --link-at-build-time to report linking errors at image build time for a class or package.
WARNING: Unknown module: org.graalvm.nativeimage.llvm specified to --add-exports
WARNING: Unknown module: org.graalvm.nativeimage.llvm specified to --add-exports
WARNING: Unknown module: org.graalvm.nativeimage.llvm specified to --add-exports
========================================================================================================================
GraalVM Native Image: Generating 'Nativo' (executable)...
========================================================================================================================
Warning: Method com.zaxxer.hikari.HikariConfig.getScheduledExecutorService() not found.
Warning: Method com.zaxxer.hikari.HikariConfig.isInitializationFailFast() not found.
Warning: Method com.zaxxer.hikari.HikariConfig.isJdbc4ConnectionTest() not found.
Warning: Method com.zaxxer.hikari.HikariConfig.setInitializationFailFast(boolean) not found.
Warning: Method com.zaxxer.hikari.HikariConfig.setJdbc4ConnectionTest(boolean) not found.
Warning: Method com.zaxxer.hikari.HikariConfig.setScheduledExecutorService(ScheduledThreadPoolExecutor) not found.
Warning: Could not resolve condition com.zaxxer.hikari.util.Sequence$Factory for reflection. Reason: java.lang.ClassNotFoundException: com.zaxxer.hikari.util.Sequence$Factory.
Warning: Could not register org.springframework.boot.diagnostics.analyzer.ValidationExceptionFailureAnalyzer: allDeclaredConstructors for reflection. Reason: java.lang.NoClassDefFoundError: javax/validation/ValidationException.
Warning: Could not register org.springframework.boot.liquibase.LiquibaseChangelogMissingFailureAnalyzer: allDeclaredConstructors for reflection. Reason: java.lang.NoClassDefFoundError: liquibase/exception/ChangeLogParseException.
[1/7] Initializing...                                                                                   (14.2s @ 0.28GB)
 Version info: 'GraalVM 22.2.0 Java 17 CE'
 Java version info: '17.0.4+8-jvmci-22.2-b06'
 C compiler: cc (apple, x86_64, 13.1.6)
 Garbage collector: Serial GC
Warning: Could not register complete reflection metadata for org.springframework.validation.beanvalidation.SpringValidatorAdapter$ViolationFieldError. Reason(s): java.lang.NoClassDefFoundError: javax/validation/Validator
[2/7] Performing analysis...  [*********]                                                               (53.4s @ 1.98GB)
  15,563 (91.42%) of 17,023 classes reachable
  24,956 (64.44%) of 38,726 fields reachable
  74,869 (61.75%) of 121,252 methods reachable
     884 classes,   311 fields, and 4,416 methods registered for reflection
      67 classes,    75 fields, and    57 methods registered for JNI access
       5 native libraries: -framework CoreServices, -framework Foundation, dl, pthread, z
[3/7] 0KBuilding universe...                                                                               (6.5s @ 4.80GB)
[4/7] 0KParsing methods...      [***]                                                                      (6.2s @ 1.73GB)
[5/7] Inlining methods...     [***]                                                                      (2.8s @ 4.23GB)
[6/7] Compiling methods...    [******]                                                                  (40.0s @ 2.19GB)
[7/7] Creating image...                                                                                  (6.6s @ 1.17GB)
  34.58MB (51.71%) for code area:    49,759 compilation units
  32.00MB (47.86%) for image heap:  351,600 objects and 327 resources
 293.56KB ( 0.43%) for other data
  66.87MB in total
------------------------------------------------------------------------------------------------------------------------
Top 10 packages in code area:                               Top 10 object types in image heap:
   1.66MB sun.security.ssl                                     7.35MB byte[] for code metadata
   1.08MB java.util                                            3.79MB java.lang.Class
 740.32KB jdk.proxy4                                           3.36MB java.lang.String
 732.49KB com.sun.crypto.provider                              3.18MB byte[] for embedded resources
 649.59KB org.apache.tomcat.util.net                           2.87MB byte[] for java.lang.String
 566.29KB java.lang.invoke                                     2.69MB byte[] for general heap data
 551.86KB org.apache.catalina.core                             1.31MB com.oracle.svm.core.hub.DynamicHubCompanion
 531.96KB com.mysql.cj.jdbc                                  890.61KB byte[] for reflection metadata
 493.46KB org.apache.coyote.http2                            697.94KB java.lang.String[]
 487.83KB java.lang                                          589.45KB java.util.HashMap$Node
  26.82MB for 636 more packages                                5.02MB for 3164 more object types
------------------------------------------------------------------------------------------------------------------------
                        5.4s (3.9% of total time) in 38 GCs | Peak RSS: 6.00GB | CPU load: 5.61
------------------------------------------------------------------------------------------------------------------------
Produced artifacts:
 /Users/jbianco/Downloads/Nativo/build/native/nativeCompile/Nativo (executable)
 /Users/jbianco/Downloads/Nativo/build/native/nativeCompile/Nativo.build_artifacts.txt (txt)
========================================================================================================================
Finished generating 'Nativo' in 2m 16s.
    [native-image-plugin] Native Image written to: /Users/jbianco/Downloads/Nativo/build/native/nativeCompile

> Task :nativeBuild
Task nativeBuild is deprecated. Use nativeCompile instead.

Deprecated Gradle features were used in this build, making it incompatible with Gradle 8.0.

You can use '--warning-mode all' to show the individual deprecation warnings and determine if they come from your own scripts or plugins.

See https://docs.gradle.org/7.5/userguide/command_line_interface.html#sec:command_line_warnings

Execution optimizations have been disabled for 1 invalid unit(s) of work during this build to ensure correctness.
Please consult deprecation warnings for more details.

BUILD SUCCESSFUL in 2m 46s
10 actionable tasks: 10 executed



build/native/nativeCompile/Nativo 
2022-08-08 22:35:51.021  INFO 2009 --- [           main] o.s.nativex.NativeListener               : AOT mode enabled

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.7.2)

2022-08-08 22:35:51.024  INFO 2009 --- [           main] n.yisu.august.Nativo.NativoApplication   : Starting NativoApplication using Java 17.0.4 on Jesus-MacBook-Pro.local with PID 2009 (/Users/jbianco/Downloads/Nativo/build/native/nativeCompile/Nativo started by jbianco in /Users/jbianco/Downloads/Nativo)
2022-08-08 22:35:51.024  INFO 2009 --- [           main] n.yisu.august.Nativo.NativoApplication   : No active profile set, falling back to 1 default profile: "default"
2022-08-08 22:35:51.055  INFO 2009 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-08-08 22:35:51.056  INFO 2009 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-08-08 22:35:51.056  INFO 2009 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.65]
2022-08-08 22:35:51.061  INFO 2009 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-08-08 22:35:51.061  INFO 2009 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 36 ms
2022-08-08 22:35:51.094  INFO 2009 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-08-08 22:35:51.094  INFO 2009 --- [           main] n.yisu.august.Nativo.NativoApplication   : Started NativoApplication in 5.092 seconds (JVM running for 5.095)
2022-08-08 22:35:51.094  INFO 2009 --- [           main] n.yisu.august.Nativo.NativoApplication   : -- Application Started (Spring Boot v2) --
2022-08-08 22:35:51.094  INFO 2009 --- [           main] n.yisu.august.Nativo.NativoApplication   : -- Java Version: 17.0.4 --
2022-08-08 22:35:51.094  INFO 2009 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2022-08-08 22:35:52.103 ERROR 2009 --- [           main] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Exception during pool initialization.

java.sql.SQLException: Can not find class 'com.mysql.cj.PerConnectionLRUFactory' specified by the 'queryInfoCacheFactory' configuration property.
	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:67) ~[na:na]
	at com.mysql.cj.jdbc.ConnectionImpl.createPreparedStatementCaches(ConnectionImpl.java:1033) ~[na:na]
	at com.mysql.cj.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:420) ~[na:na]
	at com.mysql.cj.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:241) ~[na:na]
	at com.mysql.cj.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:198) ~[Nativo:8.0.30]
	at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138) ~[na:na]
	at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:359) ~[Nativo:na]
	at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:201) ~[Nativo:na]
	at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:470) ~[na:na]
	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:561) ~[na:na]
	at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:100) ~[na:na]
	at com.zaxxer.hikari.HikariDataSource.<init>(HikariDataSource.java:81) ~[Nativo:na]
	at net.yisu.august.Nativo.Utilities.getMySQLDataSourceConnectionPool(Utilities.java:178) ~[na:na]
	at net.yisu.august.Nativo.NativoApplication.main(NativoApplication.java:31) ~[Nativo:na]
Caused by: java.lang.ClassNotFoundException: com.mysql.cj.PerConnectionLRUFactory
	at java.lang.Class.forName(DynamicHub.java:1136) ~[Nativo:na]
	at java.lang.Class.forName(DynamicHub.java:1112) ~[Nativo:na]
	at com.mysql.cj.jdbc.ConnectionImpl.createPreparedStatementCaches(ConnectionImpl.java:1025) ~[na:na]
	... 12 common frames omitted

Exception in thread "main" com.zaxxer.hikari.pool.HikariPool$PoolInitializationException: Failed to initialize pool: Can not find class 'com.mysql.cj.PerConnectionLRUFactory' specified by the 'queryInfoCacheFactory' configuration property.
	at com.zaxxer.hikari.pool.HikariPool.throwPoolInitializationException(HikariPool.java:596)
	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:582)
	at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:100)
	at com.zaxxer.hikari.HikariDataSource.<init>(HikariDataSource.java:81)
	at net.yisu.august.Nativo.Utilities.getMySQLDataSourceConnectionPool(Utilities.java:178)
	at net.yisu.august.Nativo.NativoApplication.main(NativoApplication.java:31)
Caused by: java.sql.SQLException: Can not find class 'com.mysql.cj.PerConnectionLRUFactory' specified by the 'queryInfoCacheFactory' configuration property.
	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:67)
	at com.mysql.cj.jdbc.ConnectionImpl.createPreparedStatementCaches(ConnectionImpl.java:1033)
	at com.mysql.cj.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:420)
	at com.mysql.cj.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:241)
	at com.mysql.cj.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:198)
	at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138)
	at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:359)
	at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:201)
	at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:470)
	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:561)
	... 4 more
Caused by: java.lang.ClassNotFoundException: com.mysql.cj.PerConnectionLRUFactory
	at java.lang.Class.forName(DynamicHub.java:1136)
	at java.lang.Class.forName(DynamicHub.java:1112)
	at com.mysql.cj.jdbc.ConnectionImpl.createPreparedStatementCaches(ConnectionImpl.java:1025)
	... 12 more

cd src/main/resources/META-INF/native-image
~/Downloads/Nativo/src/main/resources/META-INF/native-image]  ls -l
total 64
-rw-r--r--@ 1 jbianco  staff   129B  8 Aug 22:27 index.json
-rw-r--r--@ 1 jbianco  staff   348B  8 Aug 22:28 jni-config.json
-rw-r--r--@ 1 jbianco  staff   173B  8 Aug 22:29 proxy-config.json
-rw-r--r--@ 1 jbianco  staff   9.7K  8 Aug 22:30 reflect-config.json
-rw-r--r--@ 1 jbianco  staff    61B  8 Aug 22:30 resource-config.json
-rw-r--r--@ 1 jbianco  staff    48B  8 Aug 22:30 serialization-config.json

jbiancot avatar Aug 08 '22 20:08 jbiancot

Ah, there's a hint missing for the MySQL driver.

You can fix this in your code with:

@NativeHint(types = {
  @TypeHint(types = {
    PerConnectionLRUFactory.class
  })
})

I've added the hint for the next version of Spring native.

mhalbritter avatar Aug 09 '22 07:08 mhalbritter

Hi there,

This is still NOT functional. @mhalbritter This runs fine if I use the JVM, java -jar ... But for Native, I still have errors, and it does not run, this time the error is different.

I have added as you mentioned:

@NativeHint(types = {
		@TypeHint(types = {
				PerConnectionLRUFactory.class
		})
})

@SpringBootApplication
@EnableAsync
public class NativoApplication {

I have attached a log file "build and run native.txt" and I have attached the entire project, Nativo2.zip build and run native.txt Nativo2.zip

jbiancot avatar Aug 09 '22 13:08 jbiancot

Interesting, there are more problems lurking below. I've just added another hint to spring-native.

Can you give this a try and let me know if it works?

@NativeHint(trigger = ProxyAsyncConfiguration.class, types = {
        @TypeHint(typeNames = "org.springframework.core.annotation.TypeMappedAnnotation[]")
})

mhalbritter avatar Aug 10 '22 07:08 mhalbritter

Hi @mhalbritter it worked !!!

I will add more code to the project, and let you know how it goes.

Thanks,

jbiancot avatar Aug 11 '22 00:08 jbiancot

Hi, I switched-gears, and I added the changes you mentioned on another project, which is more realistic, it has more classes, and some features, again, I can build and run without problems if I use a JVM, java -jar ...

But when using Native, I am getting some errors, I don't know if it is because common names on some Beans? or else?

Again, I have attach the entire project on a ZIP file I have attached 2 text files, one is the build, and the other is the run "errors" shown.

I'll appreciate any help, this is a game changer for me. InhyuckProjectJava17.zip nativeBuild.txt build_native_error.txt

jbiancot avatar Aug 11 '22 01:08 jbiancot

Hey, this seems like a different problem, please open another issue. Thanks!

mhalbritter avatar Aug 11 '22 07:08 mhalbritter