GoogleCloudPlatform / cloud-sql-jdbc-socket-factory

A collection of Java libraries for connecting securely to Cloud SQL
Apache License 2.0
230 stars 119 forks source link

Add support for GraalVM #217

Open norrs opened 4 years ago

norrs commented 4 years ago

Question

How may I connect to CloudSQL via Cloud Run using a native binary with graalvm?

(I tried Quarkus and couldn't get it working with native binary, but it worked with JVM.)

I got stuck with the following stacktrace:

2020-03-20T23:00:41.791444ZGET5003.15 KB7 msChrome 80 https://api-<hidden>/job
2020-03-20T23:05:27.302460Z2020-03-20 23:05:27,302 INFO [com.goo.clo.sql.cor.CoreSocketFactory] (Agroal_20652326221) Connecting to Cloud SQL instance [xxxx:europe-north1:xxxx] via unix socket.
2020-03-20T23:05:27.303618Z2020-03-20 23:05:27,302 WARN [io.agr.pool] (Agroal_20652326221) Datasource '<default>': Something unusual has occurred to cause the driver to fail. Please report this exception.
2020-03-20T23:05:27.303661Z2020-03-20 23:05:27,302 WARN [org.hib.eng.jdb.spi.SqlExceptionHelper] (executor-thread-1) SQL Error: 0, SQLState: 99999
2020-03-20T23:05:27.303672Z2020-03-20 23:05:27,302 ERROR [org.hib.eng.jdb.spi.SqlExceptionHelper] (executor-thread-1) Something unusual has occurred to cause the driver to fail. Please report this exception.
2020-03-20T23:05:27.303688Z2020-03-20 23:05:27,303 ERROR [io.qua.ver.htt.run.QuarkusErrorHandler] (executor-thread-1) HTTP Request to /job failed, error id: 0c84d8d4-28d1-4859-92ad-55559034e0a3-6: org.jboss.resteasy.spi.UnhandledException: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection
2020-03-20T23:05:27.303699Z at org.jboss.resteasy.core.ExceptionHandler.handleApplicationException(ExceptionHandler.java:106)
2020-03-20T23:05:27.303710Z at org.jboss.resteasy.core.ExceptionHandler.handleException(ExceptionHandler.java:372)
2020-03-20T23:05:27.303721Z at org.jboss.resteasy.core.SynchronousDispatcher.writeException(SynchronousDispatcher.java:209)
2020-03-20T23:05:27.303732Z at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:496)
2020-03-20T23:05:27.303743Z at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:252)
2020-03-20T23:05:27.303754Z at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:153)
2020-03-20T23:05:27.303765Z at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:363)
2020-03-20T23:05:27.303773Z at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:156)
2020-03-20T23:05:27.303781Z at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:238)
2020-03-20T23:05:27.303790Z at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
2020-03-20T23:05:27.303802Z at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:120)
2020-03-20T23:05:27.303812Z at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.access$000(VertxRequestHandler.java:36)
2020-03-20T23:05:27.303819Z at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler$1.run(VertxRequestHandler.java:85)
2020-03-20T23:05:27.303828Z at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
2020-03-20T23:05:27.303837Z at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2011)
2020-03-20T23:05:27.303847Z at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1535)
2020-03-20T23:05:27.303859Z at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1426)
2020-03-20T23:05:27.303869Z at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
2020-03-20T23:05:27.303877Z at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
2020-03-20T23:05:27.303886Z at java.lang.Thread.run(Thread.java:834)
2020-03-20T23:05:27.303896Z at org.jboss.threads.JBossThread.run(JBossThread.java:479)
2020-03-20T23:05:27.303904Z at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:497)
2020-03-20T23:05:27.303911Z at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
2020-03-20T23:05:27.303921ZCaused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection
2020-03-20T23:05:27.303929Z at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:154)
2020-03-20T23:05:27.303939Z at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1535)
2020-03-20T23:05:27.303950Z at org.hibernate.query.Query.getResultList(Query.java:165)
2020-03-20T23:05:27.303959Z at io.quarkus.hibernate.orm.panache.runtime.PanacheQueryImpl.list(PanacheQueryImpl.java:137)
2020-03-20T23:05:27.303968Z at io.quarkus.hibernate.orm.panache.runtime.JpaOperations.listAll(JpaOperations.java:340)
2020-03-20T23:05:27.303976Z at no.frivillig.entity.Job.listAll(Job.java)
2020-03-20T23:05:27.303983Z at no.frivillig.resources.JobResource.listJobs(JobResource.java:40)
2020-03-20T23:05:27.303991Z at java.lang.reflect.Method.invoke(Method.java:566)
2020-03-20T23:05:27.304Z at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:151)
2020-03-20T23:05:27.304008Z at org.jboss.resteasy.core.MethodInjectorImpl.lambda$invoke$3(MethodInjectorImpl.java:122)
2020-03-20T23:05:27.304018Z at java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:680)
2020-03-20T23:05:27.304028Z at java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:658)
2020-03-20T23:05:27.304037Z at java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2094)
2020-03-20T23:05:27.304094Z at java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:143)
2020-03-20T23:05:27.304105Z at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:122)
2020-03-20T23:05:27.304115Z at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:594)
2020-03-20T23:05:27.304126Z at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:468)
2020-03-20T23:05:27.304137Z at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:421)
2020-03-20T23:05:27.304151Z at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:363)
2020-03-20T23:05:27.304162Z at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:423)
2020-03-20T23:05:27.304172Z at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:391)
2020-03-20T23:05:27.304184Z at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invoke$1(ResourceMethodInvoker.java:365)
2020-03-20T23:05:27.304196Z at java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1106)
2020-03-20T23:05:27.304206Z at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2235)
2020-03-20T23:05:27.304216Z at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:143)
2020-03-20T23:05:27.304226Z at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:365)
2020-03-20T23:05:27.304238Z at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:477)
2020-03-20T23:05:27.304247Z ... 19 more
2020-03-20T23:05:27.304256ZCaused by: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection
2020-03-20T23:05:27.304266Z at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:47)
2020-03-20T23:05:27.304274Z at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)
2020-03-20T23:05:27.304284Z at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)
2020-03-20T23:05:27.304297Z at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:107)
2020-03-20T23:05:27.304307Z at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:134)
2020-03-20T23:05:27.304316Z at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:50)
2020-03-20T23:05:27.304324Z at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:149)
2020-03-20T23:05:27.304334Z at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:176)
2020-03-20T23:05:27.304346Z at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:151)
2020-03-20T23:05:27.304384Z at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:2104)
2020-03-20T23:05:27.304393Z at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2034)
2020-03-20T23:05:27.304403Z at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2012)
2020-03-20T23:05:27.304412Z at org.hibernate.loader.Loader.doQuery(Loader.java:953)
2020-03-20T23:05:27.304421Z at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:354)
2020-03-20T23:05:27.304429Z at org.hibernate.loader.Loader.doList(Loader.java:2815)
2020-03-20T23:05:27.304437Z at org.hibernate.loader.Loader.doList(Loader.java:2797)
2020-03-20T23:05:27.304467Z at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2629)
2020-03-20T23:05:27.304475Z at org.hibernate.loader.Loader.list(Loader.java:2624)
2020-03-20T23:05:27.304482Z at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:506)
2020-03-20T23:05:27.304490Z at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:396)
2020-03-20T23:05:27.304499Z at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:219)
2020-03-20T23:05:27.304508Z at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1396)
2020-03-20T23:05:27.304516Z at org.hibernate.query.internal.AbstractProducedQuery.doList(AbstractProducedQuery.java:1558)
2020-03-20T23:05:27.304524Z at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1526)
2020-03-20T23:05:27.304531Z ... 44 more
2020-03-20T23:05:27.304540ZCaused by: org.postgresql.util.PSQLException: Something unusual has occurred to cause the driver to fail. Please report this exception.
2020-03-20T23:05:27.304548Z at org.postgresql.Driver.connect(Driver.java:281)
2020-03-20T23:05:27.304557Z at io.agroal.pool.ConnectionFactory.createConnection(ConnectionFactory.java:200)
2020-03-20T23:05:27.304565Z at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:390)
2020-03-20T23:05:27.304572Z at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:372)
2020-03-20T23:05:27.304580Z at java.util.concurrent.FutureTask.run(FutureTask.java:264)
2020-03-20T23:05:27.304588Z at io.agroal.pool.util.PriorityScheduledExecutor.beforeExecute(PriorityScheduledExecutor.java:65)
2020-03-20T23:05:27.304596Z at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1126)
2020-03-20T23:05:27.304605Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-03-20T23:05:27.304612Z at java.lang.Thread.run(Thread.java:834)
2020-03-20T23:05:27.304619Z ... 2 more
2020-03-20T23:05:27.304627ZCaused by: java.lang.RuntimeException: Could not load platform constants for ProtocolFamily
2020-03-20T23:05:27.304636Z at jnr.constants.platform.ConstantResolver.getConstants(ConstantResolver.java:227)
2020-03-20T23:05:27.304644Z at jnr.constants.platform.ConstantResolver.lookupAndCacheConstant(ConstantResolver.java:128)
2020-03-20T23:05:27.304651Z at jnr.constants.platform.ConstantResolver.getConstant(ConstantResolver.java:116)
2020-03-20T23:05:27.304676Z at jnr.constants.platform.ConstantResolver.longValue(ConstantResolver.java:179)
2020-03-20T23:05:27.304684Z at jnr.constants.platform.ProtocolFamily.intValue(ProtocolFamily.java:48)
2020-03-20T23:05:27.304691Z at jnr.unixsocket.SockAddrUnix.setFamily(SockAddrUnix.java:55)
2020-03-20T23:05:27.304699Z at jnr.unixsocket.UnixSocketAddress.<init>(UnixSocketAddress.java:48)
2020-03-20T23:05:27.304733Z at com.google.cloud.sql.core.CoreSocketFactory.connect(CoreSocketFactory.java:179)
2020-03-20T23:05:27.304746Z at com.google.cloud.sql.postgres.SocketFactory.createSocket(SocketFactory.java:71)
2020-03-20T23:05:27.304756Z at org.postgresql.core.PGStream.<init>(PGStream.java:67)
2020-03-20T23:05:27.304764Z at org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:91)
2020-03-20T23:05:27.304771Z at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:192)
2020-03-20T23:05:27.304780Z at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49)
2020-03-20T23:05:27.304788Z at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:211)
2020-03-20T23:05:27.304796Z at org.postgresql.Driver.makeConnection(Driver.java:458)
2020-03-20T23:05:27.304804Z at org.postgresql.Driver.connect(Driver.java:260)
2020-03-20T23:05:27.304811Z ... 10 more

Additional Context

https://github.com/quarkusio/quarkus/pull/6634 https://github.com/quarkusio/quarkus/pull/6634#issuecomment-603997307

norrs commented 4 years ago

ATM I have no example code to share as it was from a private code base. :/

kurtisvg commented 4 years ago

I really have no experience with GraalVM, so I'm not really sure what the problem might be. I'm not even sure the underlying API client (google-api-services-sqladmin) is compatible with GraalVM at the moment (/cc @lesv, who's been looking at these types of things)

One thing I see is:

2020-03-20T23:05:27.304627ZCaused by: java.lang.RuntimeException: Could not load platform constants for ProtocolFamily

which makes me think that it's actually jnr.unixsocket that isn't compatible, which also wouldn't surprise me.

You could try connecting directly instead of using the unix socket, which is the default behavior in the latest version.

norrs commented 4 years ago

@kurtisvg : Regarding connecting directly, what do you mean here?

From last time I checked the source code of this library (20 March), the contract was that it knew it was used inside a Cloud Run environment, and the configuring of the cloud run application needed a "configuration/mapping" setup for the application telling it should be able to connect to a given cloudsql instance. And my assumption is that this configuring made available an cloudsqlproxy instance listning on unix sockets for being able to allow the cloud run application to connect to the cloud sql database. Has this changed? Is this listening by IP-address now? (which would make it not use unix sockets)

I believe no due to https://github.com/GoogleCloudPlatform/cloud-sql-jdbc-socket-factory/blob/master/core/src/main/java/com/google/cloud/sql/core/CoreSocketFactory.java#L158

norrs commented 4 years ago

What's interesting is from my comment https://github.com/quarkusio/quarkus/pull/6634#issuecomment-603997307 which mentions https://github.com/oracle/graal/issues/1696 which shows an example of using unix sockets and the host has IPv6 interface available and throws the similar exception. I find https://github.com/oracle/graal/issues/1696#issuecomment-533788348 particular interesting, but I tried asking both Quarkus-dev and Graalvm-dev in their respective channels about how I could "link with Linux AMD 64 bindings" (??) when I assembled the Quarkus application. Sadly I got no feedback from how to do it with my quarkus application...

So it would be interesting to see if anyone else is capable of trying what is mentioned, to see if that solves connecting to cloudsql with a native binary in cloud run.

This is kinda a huge blocker for Java developers that are keen on pursuing serverless infrastructure with native binaries having small memory footprint and fast startup times while depending on connecting to a database.

kurtisvg commented 4 years ago

@kurtisvg : Regarding connecting directly, what do you mean here?

In v1.0.16, we no longer attempt to guess if we are on any specific environment, and instead default to connecting via TCP. It's possible to specify you wish to connect using the unix socket, but it's typically not preferable because:

  1. It's more efficient - the implementation of the GAE-standard/Flex/Cloud Run relies on the Cloud SQL proxy, which uses the same exact mechanism and path for connecting to the instance. Connect through a unix socket is just additional overhead.
  2. It's easier to debug - the SF can provide more detailed errors on why the process failed, where as the unix socket raises a "FileNotFound" error when it's unable to connect.

This is kinda a huge blocker for Java developers that are keen on pursuing serverless infrastructure with native binaries having small memory footprint and fast startup times while depending on connecting to a database.

If there is something specific to this library I can do to work around this, please let me know. I suspect the root problem is a conflict between either jnr-unixsocket or GraalVM configuration settings, and there may not be anything specific to this library that I can do.

norrs commented 4 years ago

@kurtisvg : Regarding connecting directly, what do you mean here?

In v1.0.16, we no longer attempt to guess if we are on any specific environment, and instead default to connecting via TCP.

Ill give this a new try during the weekend then!

This is kinda a huge blocker for Java developers that are keen on pursuing serverless infrastructure with native binaries having small memory footprint and fast startup times while depending on connecting to a database.

If there is something specific to this library I can do to work around this, please let me know. I suspect the root problem is a conflict between either jnr-unixsocket or GraalVM configuration settings, and there may not be anything specific to this library that I can do.

Just to clarify , I'm not blaming the library here, just hoping to maybe find some GraalVM experts that might have some more insights, but maybe this wont be an issue with v1.0.16! :-)

lesv commented 4 years ago

Roy - did upgrading to v1.0.16 work?

On Wed, May 6, 2020 at 2:44 PM Roy Sindre Norangshol < notifications@github.com> wrote:

@kurtisvg https://github.com/kurtisvg : Regarding connecting directly, what do you mean here?

In v1.0.16 https://github.com/GoogleCloudPlatform/cloud-sql-jdbc-socket-factory/releases/tag/v1.0.16, we no longer attempt to guess if we are on any specific environment, and instead default to connecting via TCP.

Ill give this a new try during the weekend then!

This is kinda a huge blocker for Java developers that are keen on pursuing serverless infrastructure with native binaries having small memory footprint and fast startup times while depending on connecting to a database.

If there is something specific to this library I can do to work around this, please let me know. I suspect the root problem is a conflict between either jnr-unixsocket or GraalVM configuration settings, and there may not be anything specific to this library that I can do.

Just to clarify , I'm not blaming the library here, just hoping to maybe find some GraalVM experts that might have some more insights, but maybe this wont be an issue with v1.0.16! :-)

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/GoogleCloudPlatform/cloud-sql-jdbc-socket-factory/issues/217#issuecomment-624907488, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAIVLDSWU6SSYIRAZJMQYNTRQHK43ANCNFSM4MZY65LA .

--

norrs commented 4 years ago

Sorry, I had personal matter that needed my attention this weekend @lesv, I'll research some time tonight from 20:00 to 21:30 to see if I can get something done for testing this. If unable to do it this evening, I'll have a look at it the following weekend. Apologize for this.

norrs commented 4 years ago

@lesv @kurtisvg :

2020-05-13 22:59:31.619 CEST2020-05-13 20:59:31,619 INFO [com.goo.clo.sql.cor.CoreSocketFactory] (Agroal_960983821) Connecting to Cloud SQL instance [coastal-dynamo-219717:europe-north1:frivillig] via SSL socket.
2020-05-13 22:59:31.619 CEST2020-05-13 20:59:31,619 INFO [com.goo.clo.sql.cor.CoreSocketFactory] (Agroal_960983821) First Cloud SQL connection, generating RSA key pair.
2020-05-13 22:59:31.830 CEST2020-05-13 20:59:31,830 CONFIG [com.goo.api.cli.htt.HttpTransport] (pool-5-thread-2) -------------- REQUEST --------------
2020-05-13 22:59:31.831 CESTGET http://metadata.google.internal/computeMetadata/v1/instance/service-accounts/default/token
2020-05-13 22:59:31.831 CESTmetadata-flavor: Google
2020-05-13 22:59:31.831 CEST
2020-05-13 22:59:31.831 CEST2020-05-13 20:59:31,830 CONFIG [com.goo.api.cli.htt.HttpTransport] (pool-5-thread-2) curl -v --compressed -H 'metadata-flavor: Google' -- 'http://metadata.google.internal/computeMetadata/v1/instance/service-accounts/default/token'
2020-05-13 22:59:31.847 CEST2020-05-13 20:59:31,847 CONFIG [com.goo.api.cli.htt.HttpTransport] (pool-5-thread-2) -------------- RESPONSE --------------
2020-05-13 22:59:31.847 CESTHTTP/1.1 200 OK
2020-05-13 22:59:31.848 CESTServer: Metadata Server for Serverless
2020-05-13 22:59:31.848 CESTMetadata-Flavor: Google
2020-05-13 22:59:31.848 CESTContent-Length: 290
2020-05-13 22:59:31.848 CESTDate: Wed, 13 May 2020 20:59:31 GMT
2020-05-13 22:59:31.848 CESTContent-Type: application/json
2020-05-13 22:59:31.848 CEST
2020-05-13 22:59:31.850 CEST2020-05-13 20:59:31,849 CONFIG [com.goo.api.cli.htt.HttpTransport] (pool-5-thread-2) Total: 290 bytes
2020-05-13 22:59:31.850 CEST2020-05-13 20:59:31,850 CONFIG [com.goo.api.cli.htt.HttpTransport] (pool-5-thread-2) {"access_token":"<MY SECRET>","expires_in":1799,"token_type":"Bearer"}
2020-05-13 22:59:31.851 CEST2020-05-13 20:59:31,850 WARN [io.agr.pool] (Agroal_960983821) Datasource '<default>': Could not create connection to database server.
2020-05-13 22:59:31.851 CEST2020-05-13 20:59:31,851 DEBUG [io.agr.pool] (Agroal_960983821) Cause: : java.sql.SQLNonTransientConnectionException: Could not create connection to database server.
2020-05-13 22:59:31.851 CEST at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:110)
2020-05-13 22:59:31.851 CEST at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97)
2020-05-13 22:59:31.851 CEST at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:89)
2020-05-13 22:59:31.851 CEST at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:63)
2020-05-13 22:59:31.851 CEST at com.mysql.cj.jdbc.ConnectionImpl.connectOneTryOnly(ConnectionImpl.java:1009)
2020-05-13 22:59:31.851 CEST at com.mysql.cj.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:826)
2020-05-13 22:59:31.851 CEST at com.mysql.cj.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:456)
2020-05-13 22:59:31.851 CEST at com.mysql.cj.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:246)
2020-05-13 22:59:31.851 CEST at com.mysql.cj.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:197)
2020-05-13 22:59:31.851 CEST at io.agroal.pool.ConnectionFactory.createConnection(ConnectionFactory.java:200)
2020-05-13 22:59:31.851 CEST at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:390)
2020-05-13 22:59:31.851 CEST at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:372)
2020-05-13 22:59:31.851 CEST at java.util.concurrent.FutureTask.run(FutureTask.java:264)
2020-05-13 22:59:31.851 CEST at io.agroal.pool.util.PriorityScheduledExecutor.beforeExecute(PriorityScheduledExecutor.java:65)
2020-05-13 22:59:31.851 CEST at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1126)
2020-05-13 22:59:31.851 CEST at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-05-13 22:59:31.851 CEST at java.lang.Thread.run(Thread.java:834)
2020-05-13 22:59:31.851 CEST at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:497)
2020-05-13 22:59:31.851 CEST at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
2020-05-13 22:59:31.851 CESTCaused by: java.lang.IllegalArgumentException:
2020-05-13 22:59:31.851 CEST at com.google.api.client.json.JsonParser.parseValue(JsonParser.java:902)
2020-05-13 22:59:31.851 CEST at com.google.api.client.json.JsonParser.parse(JsonParser.java:362)
2020-05-13 22:59:31.851 CEST at com.google.api.client.json.JsonParser.parse(JsonParser.java:337)
2020-05-13 22:59:31.851 CEST at com.google.api.client.json.JsonObjectParser.parseAndClose(JsonObjectParser.java:79)
2020-05-13 22:59:31.851 CEST at com.google.api.client.json.JsonObjectParser.parseAndClose(JsonObjectParser.java:73)
2020-05-13 22:59:31.852 CEST at com.google.api.client.http.HttpResponse.parseAs(HttpResponse.java:444)
2020-05-13 22:59:31.852 CEST at com.google.auth.oauth2.ComputeEngineCredentials.refreshAccessToken(ComputeEngineCredentials.java:153)
2020-05-13 22:59:31.852 CEST at com.google.auth.oauth2.OAuth2Credentials.refresh(OAuth2Credentials.java:157)
2020-05-13 22:59:31.852 CEST at com.google.auth.oauth2.OAuth2Credentials.getRequestMetadata(OAuth2Credentials.java:145)
2020-05-13 22:59:31.852 CEST at com.google.auth.http.HttpCredentialsAdapter.initialize(HttpCredentialsAdapter.java:91)
2020-05-13 22:59:31.852 CEST at com.google.api.client.http.HttpRequestFactory.buildRequest(HttpRequestFactory.java:88)
2020-05-13 22:59:31.852 CEST at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.buildHttpRequest(AbstractGoogleClientRequest.java:430)
2020-05-13 22:59:31.852 CEST at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:549)
2020-05-13 22:59:31.852 CEST at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.executeUnparsed(AbstractGoogleClientRequest.java:482)
2020-05-13 22:59:31.852 CEST at com.google.api.client.googleapis.services.AbstractGoogleClientRequest.execute(AbstractGoogleClientRequest.java:599)
2020-05-13 22:59:31.852 CEST at com.google.cloud.sql.core.CloudSqlInstance.fetchMetadata(CloudSqlInstance.java:277)
2020-05-13 22:59:31.852 CEST at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:125)
2020-05-13 22:59:31.852 CEST at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:57)
2020-05-13 22:59:31.852 CEST at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:78)
2020-05-13 22:59:31.852 CEST at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
2020-05-13 22:59:31.852 CEST at java.util.concurrent.FutureTask.run(FutureTask.java:264)
2020-05-13 22:59:31.852 CEST at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
2020-05-13 22:59:31.852 CEST at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2020-05-13 22:59:31.852 CEST ... 4 more
2020-05-13 22:59:31.852 CESTCaused by: java.lang.IllegalArgumentException: unable to create new instance of class com.google.api.client.util.GenericData because it has no accessible default constructor
2020-05-13 22:59:31.852 CEST at com.google.api.client.util.Types.handleExceptionForNewInstance(Types.java:162)
2020-05-13 22:59:31.852 CEST at com.google.api.client.util.Types.newInstance(Types.java:117)
2020-05-13 22:59:31.852 CEST at com.google.api.client.util.Data.newMapInstance(Data.java:539)
2020-05-13 22:59:31.852 CEST at com.google.api.client.json.JsonParser.parseValue(JsonParser.java:768)
2020-05-13 22:59:31.852 CEST ... 26 more
2020-05-13 22:59:31.852 CESTCaused by: java.lang.InstantiationException: Type `com.google.api.client.util.GenericData` can not be instantiated reflectively as it does not have a no-parameter constructor or the no-parameter constructor has not been added explicitly to the native image.
2020-05-13 22:59:31.852 CEST at java.lang.Class.newInstance(DynamicHub.java:796)
2020-05-13 22:59:31.852 CEST at com.google.api.client.util.Types.newInstance(Types.java:113)
2020-05-13 22:59:31.852 CEST ... 28 more

So errors while deserializing into a POJO from the response body from the metaserver while retrieving a token?

Added some more stuff to my configuration and seem to get past this error now by providing the following maven configuration:

        <quarkus.native.additional-build-args>-H:+ReportUnsupportedElementsAtRuntime \
                    -H:ReflectionConfigurationFiles=/usr/src/app/reflection-config.json \
                    --rerun-class-initialization-at-runtime=javax.net.ssl.SSLContext \
                    -H:-UseServiceLoaderFeature \
                    --enable-all-security-services</quarkus.native.additional-build-args>

Together with the reflection-config.json content of:

[
  {
    "name" : "com.google.cloud.sql.mysql.SocketFactory",
    "allDeclaredConstructors" : true,
    "allPublicConstructors" : true,
    "allDeclaredMethods" : true,
    "allPublicMethods" : true,
    "allDeclaredFields" : true,
    "allPublicFields" : true
  },
  {
    "name" : "com.google.api.client.json.GenericJson",
    "methods": [
      { "name": "<init>", "parameterTypes": [] }
    ],
    "allDeclaredConstructors" : true,
    "allPublicConstructors" : true,
    "allDeclaredMethods" : true,
    "allPublicMethods" : true
  },
  {
    "name" : "com.google.api.client.util.GenericData",
    "methods": [
      { "name": "<init>", "parameterTypes": [] }
    ],
    "allDeclaredConstructors" : true,
    "allPublicConstructors" : true,
    "allDeclaredMethods" : true,
    "allPublicMethods" : true
  }
]

But now Im treated with :

20-05-13 23:44:23.125 CEST2020-05-13 21:44:23,125 DEBUG [io.agr.pool] (Agroal_12332094751) Cause: : java.sql.SQLNonTransientConnectionException: Cannot connect to MySQL server on localhost:3,306.
2020-05-13 23:44:23.125 CEST
2020-05-13 23:44:23.125 CESTMake sure that there is a MySQL server running on the machine/port you are trying to connect to and that the machine this software is running on is able to connect to this host/port (i.e. not firewalled). Also make sure that the server has not been started with the --skip-networking flag.
2020-05-13 23:44:23.125 CEST
2020-05-13 23:44:23.125 CEST
2020-05-13 23:44:23.125 CEST at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:110)
2020-05-13 23:44:23.125 CEST at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97)
2020-05-13 23:44:23.125 CEST at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:89)
2020-05-13 23:44:23.125 CEST at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:63)
2020-05-13 23:44:23.125 CEST at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:73)
2020-05-13 23:44:23.125 CEST at com.mysql.cj.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:470)
2020-05-13 23:44:23.125 CEST at com.mysql.cj.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:246)
2020-05-13 23:44:23.125 CEST at com.mysql.cj.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:197)
2020-05-13 23:44:23.125 CEST at io.agroal.pool.ConnectionFactory.createConnection(ConnectionFactory.java:200)
2020-05-13 23:44:23.125 CEST at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:390)
2020-05-13 23:44:23.125 CEST at io.agroal.pool.ConnectionPool$CreateConnectionTask.call(ConnectionPool.java:372)
2020-05-13 23:44:23.125 CEST at java.util.concurrent.FutureTask.run(FutureTask.java:264)
2020-05-13 23:44:23.125 CEST at io.agroal.pool.util.PriorityScheduledExecutor.beforeExecute(PriorityScheduledExecutor.java:65)
2020-05-13 23:44:23.125 CEST at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1126)
2020-05-13 23:44:23.125 CEST at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2020-05-13 23:44:23.125 CEST at java.lang.Thread.run(Thread.java:834)
2020-05-13 23:44:23.125 CEST at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:497)
2020-05-13 23:44:23.125 CEST at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
2020-05-13 23:44:23.125 CESTCaused by: java.lang.NullPointerException
2020-05-13 23:44:23.125 CEST at com.mysql.cj.jdbc.ConnectionImpl.connectOneTryOnly(ConnectionImpl.java:980)
2020-05-13 23:44:23.125 CEST at com.mysql.cj.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:826)
2020-05-13 23:44:23.125 CEST at com.mysql.cj.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:456)
2020-05-13 23:44:23.125 CEST ... 12 more
2020-05-13 23:44:23.128 CEST2020-05-13 21:44:23,127 WARN [org.hib.eng.jdb.spi.SqlExceptionHelper] (executor-thread-1) SQL Error: 0, SQLState: 08S01
2020-05-13 23:44:23.128 CEST2020-05-13 21:44:23,127 ERROR [org.hib.eng.jdb.spi.SqlExceptionHelper] (executor-thread-1) Cannot connect to MySQL server on localhost:3,306.
2020-05-13 23:44:23.128 CEST
2020-05-13 23:44:23.128 CESTMake sure that there is a MySQL server running on the machine/port you are trying to connect to and that the machine this software is running on is able to connect to this host/port (i.e. not firewalled). Also make sure that the server has not been started with the --skip-networking flag.

Sadly 08S01 seems like it can be many things according to https://dev.mysql.com/doc/connector-j/8.0/en/connector-j-reference-error-sqlstates.html

Another ugly side effect is that quarkus is logging the jdbc url with the secrets (but this is something Quarkus should fix) :

2020-05-13 21:36:05,012 DEBUG [io.qua.agr.run.AbstractDataSourceProducer] (main) Started datasource <default> connected to jdbc:mysql:///quarkus_test?cloudSqlInstance=coastal-dynamo-219717:europe-north1:frivillig&socketFactory=com.google.cloud.sql.mysql.SocketFactory&user=quarkus_test&password=<eeek>&useSSL=false
norrs commented 4 years ago

Have a look by checking https://github.com/norrs/quarkus-quickstarts/tree/mysql_cloudrun_cloudsql/hibernate-orm-panache-quickstart . A hint for compiling and deploying can be done by :

rockj@qhira:~/dev/quarkus-quickstarts/hibernate-orm-panache-quickstart (mysql_cloudrun_cloudsql=)$ cloud-build-local -dryrun=false -config=cloudbuild-native.yaml -substitutions=TAG_NAME=demo-0.0.7 -bind-mount-source=false .

Notice after the first deploy, you need to edit the cloud run deployment and add the Cloud SQL and you need to add two additional properties, DB_USER and DB_PASSWORD

norrs commented 4 years ago

This time I tried MySQL btw and not PostgreSQL. I can also jump on a meet session if that is helpful, my timezone is CEST. (GMT+2). Time for :zzz: now.

kurtisvg commented 4 years ago

Looks to me like the problem is originating from the google-api-client:

2020-05-13 22:59:31.852 CESTCaused by: java.lang.IllegalArgumentException: unable to create new instance of class com.google.api.client.util.GenericData because it has no accessible default constructor
2020-05-13 22:59:31.852 CEST at com.google.api.client.util.Types.handleExceptionForNewInstance(Types.java:162)
2020-05-13 22:59:31.852 CEST at com.google.api.client.util.Types.newInstance(Types.java:117)
2020-05-13 22:59:31.852 CEST at com.google.api.client.util.Data.newMapInstance(Data.java:539)
2020-05-13 22:59:31.852 CEST at com.google.api.client.json.JsonParser.parseValue(JsonParser.java:768)
2020-05-13 22:59:31.852 CEST ... 26 more
2020-05-13 22:59:31.852 CESTCaused by: java.lang.InstantiationException: Type `com.google.api.client.util.GenericData` can not be instantiated reflectively as it does not have a no-parameter constructor or the no-parameter constructor has not been added explicitly to the native image.
2020-05-13 22:59:31.852 CEST at java.lang.Class.newInstance(DynamicHub.java:796)
2020-05-13 22:59:31.852 CEST at com.google.api.client.util.Types.newInstance(Types.java:113)
2020-05-13 22:59:31.852 CEST ... 28 more

So it looks like we've traded one dependency issue for another unfortunately.

@lesv - have you tried any of the generated libraries with GraalVM before?

lesv commented 4 years ago

No, but @ludoch has, he wrote a doc, I was going to get into it in a few weeks. My understanding is that there are some issues w/ protobuf handling and some issues w/ gRPC. @kurtisvg If you'd like me to setup an experiment, I can do it next week.

kurtisvg commented 4 years ago

I haven't had the opportunity to experiment with GraalVM, so any suggestions are welcome.

I don't think this is necessarily a blocker, as Cloud Run now has Serverless VPC access in beta. This means it's possible to connect directly to Cloud SQL via Private IP without the use of this library.

viniciusccarvalho commented 4 years ago

Because I got stuck on this two months ago, I thought it may be worthwhile sharing some of my findings too

PostgreSQL does not seems to be supported due the fact the driver users jnr-ffi and that does not seems to be supported.

I tried mysql, but according to the micronaut docs, there seems to be an issue with mysql driver too: issue

I got mariadb driver to work in a native build using SQL proxy not this connector. Trying to use the connector I had several issues with our GCP libraries and SSL, after creating my own SocketFactory for mariadb, I got past the errors on the DB and then issues happened at the auth libraries. Followed all the instructions on the doc mentioned here (just happens I work at google and have access to the doc too), but still had issues with several of our libraries. I got stuck at the Keystore throwing NPE, even after bundling the cacerts with the application as instructed.

I have not tried the VPC service connector, that may be a good approach, as mariadb driver works fine to write native code with micronaut at least.

norrs commented 4 years ago

@kurtisvg : So the sad part about Serverless VPC access is additional charges for network traffic, it might be fine for larger enterprises who has too much money :upside_down_face: EDIT: Also feels weird having to enable a VPC when it is within the same project as well.

ludoch commented 4 years ago

GraalVM is taking off, and many apps will need a SQL story with it... Beta and expensive workarounds will not work with all customers. Also, do not under estimate local development and local testing, so I would recommend we spend time to address this issue (and all related to GraalVM in GCP libraries)...

viniciusccarvalho commented 4 years ago

Another thing I bumped into, after being able to deploy the micronaut + cloud sql using VPC connector is that the image is consuming all available memory that is given to it. As reported here: https://github.com/oracle/graal/issues/2428 seems to be an issue that some GraalVM applications have.

I noticed that the java version does not "leak" memory, it does however requires more memory to start, and takes way longer to bootstrap too, but at least its not having GC issues.

shubha-rajan commented 3 years ago

Update on this: we're currently blocked from moving forward on GraalVM support because the SQLAdmin API client, which the socket factory depends on, is not supported.

AlexandreGuidin commented 3 years ago

Do we have any new update about this? 1.3.0 was released https://github.com/GoogleCloudPlatform/cloud-sql-jdbc-socket-factory/releases

1.3.0 give error while builing with quarkus

Error: com.oracle.graal.pointsto.constraints.UnresolvedElementException: Discovered unresolved method during parsing: com.google.auth.http.HttpCredentialsAdapter.getCredentials(). To diagnose the issue you can use the --allow-incomplete-classpath option. The missing method is then reported at run time when it is accessed the first time.
Detailed message:
Trace: 
        at parsing com.google.cloud.sql.core.CloudSqlInstance.<init>(CloudSqlInstance.java:154)
Call path from entry point to com.google.cloud.sql.core.CloudSqlInstance.<init>(String, SQLAdmin, boolean, CredentialFactory, ListeningScheduledExecutorService, ListenableFuture): 
        at com.google.cloud.sql.core.CloudSqlInstance.<init>(CloudSqlInstance.java:133)

I've tried to reach the same error of @norrs, with v1.2.3 but i'm stuck with some SSL problem

2021-06-06T15:12:43.067057Z{"severity": "ERROR", "at": "2021-06-06T15:12:43+0000", "class": "io.quarkus.runtime.ApplicationLifecycleManager", "message": "Failed to start application (with profile prod)", "error": ": java.lang.NullPointerException
Default
2021-06-06T15:12:43.067075Z at com.google.api.client.util.SecurityUtils.loadKeyStore(SecurityUtils.java:82)
Default
2021-06-06T15:12:43.067080Z at com.google.api.client.googleapis.GoogleUtils.getCertificateTrustStore(GoogleUtils.java:86)
dzou commented 3 years ago

Do we have any new update about this? 1.3.0 was released https://github.com/GoogleCloudPlatform/cloud-sql-jdbc-socket-factory/releases

1.3.0 give error while builing with quarkus

Error: com.oracle.graal.pointsto.constraints.UnresolvedElementException: Discovered unresolved method during parsing: com.google.auth.http.HttpCredentialsAdapter.getCredentials(). To diagnose the issue you can use the --allow-incomplete-classpath option. The missing method is then reported at run time when it is accessed the first time.
Detailed message:
Trace: 
        at parsing com.google.cloud.sql.core.CloudSqlInstance.<init>(CloudSqlInstance.java:154)
Call path from entry point to com.google.cloud.sql.core.CloudSqlInstance.<init>(String, SQLAdmin, boolean, CredentialFactory, ListeningScheduledExecutorService, ListenableFuture): 
        at com.google.cloud.sql.core.CloudSqlInstance.<init>(CloudSqlInstance.java:133)

I've tried to reach the same error of @norrs, with v1.2.3 but i'm stuck with some SSL problem

2021-06-06T15:12:43.067057Z{"severity": "ERROR", "at": "2021-06-06T15:12:43+0000", "class": "io.quarkus.runtime.ApplicationLifecycleManager", "message": "Failed to start application (with profile prod)", "error": ": java.lang.NullPointerException
Default
2021-06-06T15:12:43.067075Z at com.google.api.client.util.SecurityUtils.loadKeyStore(SecurityUtils.java:82)
Default
2021-06-06T15:12:43.067080Z at com.google.api.client.googleapis.GoogleUtils.getCertificateTrustStore(GoogleUtils.java:86)

We're currently working on getting Cloud SQL working for GraalVM native image in the google-cloud-graalvm-support project here: https://github.com/GoogleCloudPlatform/google-cloud-graalvm-support/pull/143

We got a sample successfully working for Cloud SQL with MySQL in the PR, though our method relies on using the --allow-incomplete-classpath setting.

enocom commented 1 year ago

Related: https://github.com/GoogleCloudPlatform/cloud-sql-jdbc-socket-factory/issues/824.