1

Here's the docs of the management of the connection pool, and looks like maxIdleTime property is responsible for closing the connection. But unfortunately every 4-5 second 3 debug message still comes with some weird title testAvailableItems.

Here is the reproducible code and below is the logs.

val dataTableName: String = "prefix_data",
val logTableName: String = "prefix_log",
private val suspendingConnection: SuspendingConnection =
        PostgreSQLConnectionBuilder
            .createConnectionPool(
                "postgres://$host:$port/$database?user=$username&password=$password"
            ) {
                maxIdleTime = TimeUnit.SECONDS.toMillis(10), // 10 seconds (in millis, Long value)
            }.asSuspending

suspend fun setup() = suspendingConnection
    .sendQuery(
        """
        |CREATE TABLE IF NOT EXISTS $dataTableName (
        |  id serial primary key,
        |  plugin_name varchar(45) NOT NULL,
        |  key varchar(90) NOT NULL,
        |  data text NOT NULL,
        |  timestamp timestamp DEFAULT current_timestamp,
        |  UNIQUE(plugin_name,key)
        |);
        |
        |CREATE TABLE IF NOT EXISTS $logTableName (
        |  id serial primary key,
        |  origin varchar(45) NOT NULL,
        |  message text NOT NULL,
        |  timestamp timestamp DEFAULT current_timestamp
        |);
        """.trimMargin()
    )

suspend fun main() {
    setup()
    // It does sends the close message after 10 seconds but still the logs increase rapidly every 5 seconds with a title `testAvailableItems`
}
[db-sql-netty-thread-1] TRACE com.github.jasync.sql.db.postgresql.codec.PostgreSQLConnectionHandler - got message com.github.jasync.sql.db.postgresql.messages.backend.ReadyForQueryMessage@780b88c7
[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - received message: GiveBack: <postgres-connection-1> hasError=false ; availableItems=0 waitingQueue=0 inUseItems=1 inCreateItems=0 ActorCoroutine{Active}@1f6f7d35
[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - add <postgres-connection-1> to available items, size is 1
[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - scheduleNewItemsIfNeeded - availableItems=1 waitingQueue=0 inUseItems=0 inCreateItems=0 ActorCoroutine{Active}@1f6f7d35
[pool-1-thread-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - testAvailableItems - starting
[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - received message: TestAvailableItems @1931541018 ; availableItems=1 waitingQueue=0 inUseItems=0 inCreateItems=0 ActorCoroutine{Active}@1f6f7d35
[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - test: <postgres-connection-1> available 12687 ms
[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - releasing idle item <postgres-connection-1>
[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - destroy item <postgres-connection-1>
[db-sql-netty-thread-1] TRACE com.github.jasync.sql.db.postgresql.codec.MessageEncoder - Sending message CloseMessage
0: 58 00 00 00 04              X . . . . 
Total 5 bytes read

[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - testAvailableItems - done testing
[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - scheduleNewItemsIfNeeded - availableItems=0 waitingQueue=0 inUseItems=0 inCreateItems=0 ActorCoroutine{Active}@1f6f7d35
[db-sql-netty-thread-1] INFO com.github.jasync.sql.db.postgresql.codec.PostgreSQLConnectionHandler - Connection disconnected - null
[pool-1-thread-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - testAvailableItems - starting
[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - received message: TestAvailableItems @1771095482 ; availableItems=0 waitingQueue=0 inUseItems=0 inCreateItems=0 ActorCoroutine{Active}@1f6f7d35
[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - testAvailableItems - done testing
[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - scheduleNewItemsIfNeeded - availableItems=0 waitingQueue=0 inUseItems=0 inCreateItems=0 ActorCoroutine{Active}@1f6f7d35
[pool-1-thread-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - testAvailableItems - starting
[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - received message: TestAvailableItems @1904368932 ; availableItems=0 waitingQueue=0 inUseItems=0 inCreateItems=0 ActorCoroutine{Active}@1f6f7d35
[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - testAvailableItems - done testing
[DefaultDispatcher-worker-1] TRACE com.github.jasync.sql.db.pool.ActorBasedObjectPool - scheduleNewItemsIfNeeded - availableItems=0 waitingQueue=0 inUseItems=0 inCreateItems=0 ActorCoroutine{Active}@1f6f7d35
// ... these 3 lines continues forever every 5 seconds

How do I really close the connection when the database is not in use (such as after 10 seconds of not in use)?

Animesh Sahu
  • 7,445
  • 2
  • 21
  • 49

1 Answers1

1

The connections are actually closed.
The log messages you see here are of the pool itself triggering a test for live connections every 5 seconds.
You can see in the message: availableItems=0 waitingQueue=0 inUseItems=0 inCreateItems=0 (each item is a connection) which means there are no open connections.

oshai
  • 14,865
  • 26
  • 84
  • 140
  • Is there any way to ensure there is no resources are wasted (like stop the logging tasks when idle for k amount of seconds) until we submit a new query? – Animesh Sahu Jun 19 '20 at 12:39
  • It's probably possible, but trace logging are used to debug issues. On regular production code if that bothers you, it should just been turned off (ie: change the level to info). – oshai Jun 21 '20 at 07:55