"Already connected" error when locally testing App Engine connection to Cloud SQL

[michaeltheshah]

I'm connecting to my Cloud SQL instance inside App Engine. This is how I set up the connection with HikariCP:

private val dataSource: HikariDataSource by lazy {
        val config = HikariConfig()

        config.jdbcUrl = "jdbc:postgresql://google/db-name"
        config.username = "username"
        config.password = "password"

        config.addDataSourceProperty("socketFactory", "com.google.cloud.sql.postgres.SocketFactory")
        config.addDataSourceProperty("cloudSqlInstance", "project:region:instance")

        HikariDataSource(config)
    }

While trying to connect to my PostgreSQL instance via App Engine locally, I keep getting this stacktrace:

java.lang.ExceptionInInitializerError
	at appengine.profile.CheckUsernameExists.doGet(CheckUsernameExists.kt:34)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:873)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1623)
	at com.google.appengine.tools.development.ResponseRewriterFilter.doFilter(ResponseRewriterFilter.java:134)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
	at com.google.appengine.tools.development.HeaderVerificationFilter.doFilter(HeaderVerificationFilter.java:34)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
	at com.google.appengine.api.blobstore.dev.ServeBlobFilter.doFilter(ServeBlobFilter.java:63)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
	at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:48)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
	at com.google.appengine.tools.development.jetty9.StaticFileFilter.doFilter(StaticFileFilter.java:123)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
	at com.google.appengine.tools.development.DevAppServerModulesFilter.doDirectRequest(DevAppServerModulesFilter.java:366)
	at com.google.appengine.tools.development.DevAppServerModulesFilter.doDirectModuleRequest(DevAppServerModulesFilter.java:349)
	at com.google.appengine.tools.development.DevAppServerModulesFilter.doFilter(DevAppServerModulesFilter.java:116)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
	at com.google.appengine.tools.development.DevAppServerRequestLogFilter.doFilter(DevAppServerRequestLogFilter.java:44)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:524)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1700)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1667)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
	at com.google.appengine.tools.development.jetty9.DevAppEngineWebAppContext.doScope(DevAppEngineWebAppContext.java:94)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
	at com.google.appengine.tools.development.jetty9.JettyContainerService$ApiProxyHandler.handle(JettyContainerService.java:595)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
	at org.eclipse.jetty.server.Server.handle(Server.java:505)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:370)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:267)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:698)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:804)
	at java.lang.Thread.run(Thread.java:745)
Caused by: com.zaxxer.hikari.pool.HikariPool$PoolInitializationException: Failed to initialize pool: The connection attempt failed.
	at com.zaxxer.hikari.pool.HikariPool.throwPoolInitializationException(HikariPool.java:597)
	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:576)
	at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:115)
	at com.zaxxer.hikari.HikariDataSource.<init>(HikariDataSource.java:81)
	at appengine.sql.repository.ProfileRepository.<clinit>(ProfileRepository.kt:50)
	... 48 more
Caused by: org.postgresql.util.PSQLException: The connection attempt failed.
	at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:262)
	at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:67)
	at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:216)
	at org.postgresql.Driver.makeConnection(Driver.java:406)
	at org.postgresql.Driver.connect(Driver.java:274)
	at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:121)
	at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:353)
	at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:201)
	at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:473)
	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:562)
	... 51 more
Caused by: java.net.SocketException: already connected
	at java.net.Socket.connect(Socket.java:569)
	at sun.security.ssl.SSLSocketImpl.connect(SSLSocketImpl.java:668)
	at org.postgresql.core.PGStream.<init>(PGStream.java:64)
	at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:133)
	... 60 more

I was certain that I set up everything correctly, but I keep getting this error, what am I doing wrong? I'm stumped.

[kurtisvg]

Which version of the connector are you using?

It also looks like this sample is in Kotlin, which I don't have much experience in. It does look like you are using Servlets - I suggest taking a look at our sample with Postgres for how to safely create a connection pool.

[kurtisvg]

There is a post on SO with a similar issue. Is this your post as well?

[michaeltheshah]

Yeah that's my post on SO. Looks like no one else has ever gotten the issue :/

dependencies {
    implementation 'org.apache.httpcomponents:httpclient:4.5.9'
    implementation 'com.zaxxer:HikariCP:3.3.1'
    implementation 'com.google.cloud.sql:postgres-socket-factory:1.0.15'
    implementation 'org.postgresql:postgresql:42.2.1'
}

Here are the relevant dependencies I'm using.

[kurtisvg]

I think (but again, not a Kotlin expert), that you are using it wrong (based on your SO post).

private val dataSource = HikariDataSource(config)

private val connection = dataSource.connection

IIRC, ds.connection is really ds.getConnection(), which returns checked out a connection from the pool, which must be closed afterwards to check it back in. When you call connection.use, the connection is closed at the end of the statement, and can't be reused again. (It might be possible to use ds.connection.use, but I'm not sure).

If you are using Servlets, you also don't want to be using a global value for the servlet, but instead use a ContextListener (like in the example I linked above) to share the pool between requests.

[michaeltheshah]

Now I'm getting this error 🤦‍♂️

java.lang.NullPointerException
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1602)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:524)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1700)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1667)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
        at com.google.appengine.tools.development.jetty9.DevAppEngineWebAppContext.doScope(DevAppEngineWebAppContext.java:94)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at com.google.appengine.tools.development.jetty9.JettyContainerService$ApiProxyHandler.handle(JettyContainerService.java:595)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at org.eclipse.jetty.server.Server.handle(Server.java:505)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:370)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:267)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
        at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:698)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:804)
        at java.lang.Thread.run(Thread.java:745)

[michaeltheshah]

Hmm... so even with moving the config and dataSource objects to the ConnectionPoolContextListener, I'm still getting the already connected exception.

[kurtisvg]

Can you provide examples of your context listener and servlet?

[michaeltheshah]

Context listener:

package appengine

import com.zaxxer.hikari.HikariConfig
import com.zaxxer.hikari.HikariDataSource
import javax.servlet.ServletContextEvent
import javax.servlet.ServletContextListener
import java.sql.SQLException
import javax.servlet.annotation.WebListener
import javax.sql.DataSource

@WebListener("Creates a connection pool that is stored in the Servlet's context for later use.")
class ConnectionPoolContextListener: ServletContextListener {
    private val DB_USER = System.getenv("DB_USER")
    private val DB_PASS = System.getenv("DB_PASS")
    private val DB_NAME = System.getenv("DB_NAME")
    private val CLOUD_SQL_INSTANCE_NAME = System.getenv("CLOUD_SQL_INSTANCE_NAME")

    override fun contextInitialized(event: ServletContextEvent?) {
        var pool = event?.servletContext?.getAttribute(Constants.DB_CONTEXT) as? DataSource

        if (pool == null) {
            pool = createConnectionPool()
            event?.servletContext?.setAttribute(Constants.DB_CONTEXT, pool)
        }
    }

    override fun contextDestroyed(event: ServletContextEvent?) {
        val pool = event?.servletContext?.getAttribute(Constants.DB_CONTEXT) as? HikariDataSource
        pool?.close()
    }

    private fun createConnectionPool(): DataSource {
        val config = HikariConfig().apply {
            jdbcUrl = "jdbc:postgresql://google/$DB_NAME"
            username = DB_USER
            password = DB_PASS

            addDataSourceProperty("socketFactory", "com.google.cloud.sql.postgres.SocketFactory")
            addDataSourceProperty("cloudSqlInstance", CLOUD_SQL_INSTANCE_NAME)
        }

        return HikariDataSource(config)
    }
}

Servlet:

package appengine.profile

import appengine.Constants
import appengine.ErrorCodes
import appengine.Servlet
import appengine.sendErrorAsJson
import java.lang.Exception
import javax.servlet.annotation.WebServlet
import javax.servlet.http.HttpServletRequest
import javax.servlet.http.HttpServletResponse
import javax.sql.DataSource

@WebServlet(urlPatterns = ["/v1/profiles/checkusername"])
class CheckUsernameExists: Servlet() {
    override fun doGet(req: HttpServletRequest?, resp: HttpServletResponse?) {
        val dataSource = req?.servletContext?.getAttribute(Constants.DB_CONTEXT) as DataSource

        val username = req.getParameter("username") ?: ""

        try {
            dataSource.connection.use { connection ->
                connection.prepareCall("SELECT EXISTS(SELECT 1 FROM profiles WHERE username = '$username')").use { statement ->
                    statement.executeQuery().use { resultSet ->
                        try {
                            val exists = generateSequence {
                                if (resultSet.next()) resultSet.getBoolean(1) else null
                            }.toList()
                            resp?.writer?.write(gson.toJson(exists.any { it }))
                        } catch (e: Exception) {
                            resp?.sendErrorAsJson(ErrorCodes.SC_INTERNAL_SERVER_ERROR, e.localizedMessage)
                        }
                    }
                }
            }
        } catch (e: Exception) {
            resp?.sendErrorAsJson(ErrorCodes.SC_INTERNAL_SERVER_ERROR, e.localizedMessage)
        }
    }
}

data class Exists(val exists: Boolean)

[kurtisvg]

@lesv - Would you mind taking a look at the above example? I'm not very up to date on Kotlin

[lesv]

Ack - will try building this tomorrow.

@mochat97 Are you using a Java11 runtime on GAE? or something else? Which version of Jetty are you using? Are you using any Jetty / Hikari configuration magic (if so, what?), or is it all just in your fatJar?

[michaeltheshah]

@lesv I'm using Java 8 on GAE. Looks like it's Jetty 9.4.18.v20190429. I'm not using the configuration magic, it's all in the jar.

[lesv]

Thanks - looks like it will probably be Monday. To confirm, it's GAE/standard or GAE/Flex?

[michaeltheshah]

GAE/standard. Thanks so much!

[lesv]

I'm just getting started, had a few other things pop up today, and discovered a surprisingly large amount of stuff that's obsolete in our docs. That said, your ContextListener and how use it w/ Hikari on the surface looks correct. I'll have more for you on Monday.