Unexpected reset autoCommit on connection HikarCP

Question

I am using Scala, Hikari, Doobie, cats Fiber & Timer, monix Task.

I am periodically running a SQL query and then process the results. The periodic Task runs forever.

import cats.effect.{Fiber, Timer}
import cats.implicits._
import monix.eval.Task
import monix.reactive.Observable

// ....

  def run(xa: Transactor[Task]): Task[Fiber[Task, Nothing]] = {
    logger.info(s"Starting, delay: ${config.delay}")
    (execute(xa) *> timer.sleep(config.delay)).foreverM.start
  }

  private def execute(xa: Transactor[Task]): Task[List[Option[CallResult]]] = {
    callModel
      .findPending(config.maxTries)
      .transact(xa)
      .flatMap { calls =>
        logger.debug(s"executing: ${calls.size}")
        Observable(calls: _*)
          .mapParallelUnordered(config.parallelism) {
            case (call, callDetails) => executeCall(call, callDetails)
          }
          .toListL
          .orElse {
            logger.debug(s"fallbacking to empty list...")
            Task.now(List.empty)
          }
      }
  }

  private def executeCall(call: Call, callDetails: CallDetails): Task[Option[CallResult]] = ???

The problem is that every time query is transacted with HikariTransaction it prints to logs that Connection has Reset autoCommit value.

16:48:41.350 [pool-3-thread-114] DEBUG c.z.h.p.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@1b3168db
16:48:41.355 [pool-3-thread-114] DEBUG c.z.h.p.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@1b3168db
16:48:41.592 [HikariPool-1 housekeeper] DEBUG c.z.h.p.HikariPool - HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
16:48:46.355 [pool-3-thread-114] DEBUG c.z.h.p.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@1b3168db
16:48:46.359 [pool-3-thread-114] DEBUG c.z.h.p.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@1b3168db
16:48:51.361 [pool-3-thread-114] DEBUG c.z.h.p.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@1b3168db
16:48:51.365 [pool-3-thread-116] DEBUG c.z.h.p.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@6cf8c3b4
16:48:56.367 [pool-3-thread-114] DEBUG c.z.h.p.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@1b3168db
16:48:56.370 [pool-3-thread-116] DEBUG c.z.h.p.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@6cf8c3b4
16:49:01.374 [pool-3-thread-114] DEBUG c.z.h.p.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@1b3168db
16:49:01.374 [pool-3-thread-116] DEBUG c.z.h.p.PoolBase - HikariPool-1 - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@6cf8c3b4
16:49:05.166 [HikariPool-1 connection closer] DEBUG c.z.h.p.PoolBase - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@942b76d: (connection has passed maxLifetime)
16:49:05.186 [HikariPool-1 connection adder] DEBUG c.z.h.p.HikariPool - HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@41905dfe

But I am not modifying the autoCommit value anywhere. I am using defaults for HikariCP as autoCommit=true

09:00:02.184 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - HikariPool-1 - configuration:
09:00:02.190 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - allowPoolSuspension.............false
09:00:02.191 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - autoCommit......................true
09:00:02.191 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - catalog.........................none
09:00:02.192 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - connectionInitSql...............none
09:00:02.192 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - connectionTestQuery.............none
09:00:02.193 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - connectionTimeout...............30000
09:00:02.193 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - dataSource......................none
09:00:02.193 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - dataSourceClassName.............none
09:00:02.194 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - dataSourceJNDI..................none
09:00:02.196 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - dataSourceProperties............{password=<masked>}
09:00:02.197 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - driverClassName.................none
09:00:02.197 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - healthCheckProperties...........{}
09:00:02.198 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - healthCheckRegistry.............none
09:00:02.198 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - idleTimeout.....................600000
09:00:02.198 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - initializationFailTimeout.......1
09:00:02.199 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - isolateInternalQueries..........false
09:00:02.199 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - jdbcUrl.........................jdbc:postgresql://database:5432/carsdb
09:00:02.200 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - leakDetectionThreshold..........0
09:00:02.200 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - maxLifetime.....................1800000
09:00:02.200 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - maximumPoolSize.................10
09:00:02.201 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - metricRegistry..................none
09:00:02.201 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - metricsTrackerFactory...........none
09:00:02.201 [pool-2-thread-1] DEBUG c.z.h.HikariConfig - minimumIdle.....................10

Problem

I can't figure out why Hikari prints such logs. I am not modifying the connection autoCommit field anywhere. Is there something I am missing in this? It looks like connections are returned back to the pool right after calling transact(xa) which is good. But for some reason they seem to have changed autoCommit value.

Versions I use:

Hikari 3.3.1.
doobie-hikari: 0.7.0
doobie-postgres: 0.7.0

I don't want to keep connection open. I'd rather release it back to connection pool (as it is now). But I'm struggling why it changes (?) `autoCommit` setting — Dariusz Mydlarz, Jun 27 '19 at 11:48
See https://stackoverflow.com/questions/41202242/reset-autocommit-on-connection-in-hikaricp — Ori Marko, Jun 27 '19 at 11:51
Was there already. But my code is not changing the autoCommit connection value, that's why I can't get a solution — Dariusz Mydlarz, Jun 27 '19 at 11:55
I assume that something called 'transactor' will use transactions, and the default for connections is to be in auto commit, but using transactions will disable autocommit, and Hikari will reset this. Maybe you should move the logging level to INFO and ignore Hikari DEBUG logging? — Mark Rotteveel, Jun 27 '19 at 14:44

Unexpected reset autoCommit on connection HikarCP

0 Answers0