Skip to content

newSuspendedTransaction connecting to old database instances across test cases #1607

Open
@vinh0604

Description

@vinh0604

Hi,
I'm working on a web service using Ktor 1.6.8 and Exposed 0.39.2.
My application module and database is setup as following:

fun Application.module(testing: Boolean = false) {
 val hikariConfig =
    HikariConfig().apply {
      driverClassName = "org.postgresql.Driver"
      jdbcUrl = environment.config.propertyOrNull("ktor.database.url")?.getString()
      username = environment.config.propertyOrNull("ktor.database.username")?.getString()
      password = environment.config.propertyOrNull("ktor.database.password")?.getString()
      maximumPoolSize = 10
      isAutoCommit = false
      transactionIsolation = "TRANSACTION_REPEATABLE_READ"
      validate()
    }
  val pool =  HikariDataSource(hikariConfig)
  val db = Database.connect(pool, {}, DatabaseConfig { useNestedTransactions = true })
}

I use ktor-server-test-host, Test Containers and junit 5 to test the service. My test looks similar like below:

@Testcontainers
class SampleApplicationTest{
  companion object {
    @Container
    val postgreSQLContainer = PostgreSQLContainer<Nothing>(DockerImageName.parse("postgres:13.4-alpine")).apply {
      withDatabaseName("database_test")
    }
  }

  @Test
  internal fun `should make request successfully`() {
    withTestApplication({
      (environment.config as MapApplicationConfig).apply {
        put("ktor.database.url", postgreSQLContainer.jdbcUrl)
        put("ktor.database.user", postgreSQLContainer.username)
        put("ktor.database.password", postgreSQLContainer.password)
      }
      module(testing = true) 
    }) {
      handleRequest(...)
    }
  }
}

I observed an issue that if I ran multiple test classes together, some requests ended up using old Exposed db instance that was setup in a previous test class, causing the test case failed because the underlying database was already stopped.
When I ran one test class at a time, all were running fine.
Please refer to the log below for the error stack trace:

2022-10-01 08:00:36.102 [DefaultDispatcher-worker-5 @request#103] WARN  Exposed - Transaction attempt #1 failed: java.sql.SQLTransientConnectionException: HikariPool-4 - Connection is not available, request timed out after 30001ms.. Statement(s): INSERT INTO cards (...)
org.jetbrains.exposed.exceptions.ExposedSQLException: java.sql.SQLTransientConnectionException: HikariPool-4 - Connection is not available, request timed out after 30001ms.
        at org.jetbrains.exposed.sql.statements.Statement.executeIn$exposed_core(Statement.kt:49)
        at org.jetbrains.exposed.sql.Transaction.exec(Transaction.kt:143)
        at org.jetbrains.exposed.sql.Transaction.exec(Transaction.kt:128)
        at org.jetbrains.exposed.sql.statements.Statement.execute(Statement.kt:28)
        at org.jetbrains.exposed.sql.QueriesKt.insert(Queries.kt:73)
        at com.example.application.services.CardService$createCard$row$1.invokeSuspend(CardService.kt:53)
        at org.jetbrains.exposed.sql.transactions.experimental.SuspendedKt$suspendedTransactionAsyncInternal$1.invokeSuspend(Suspended.kt:127)
        at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
        at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106)
        at kotlinx.coroutines.internal.LimitedDispatcher.run(LimitedDispatcher.kt:42)
        at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:95)
        at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:570)
        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:750)
        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:677)
        at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:664)
Caused by: java.sql.SQLTransientConnectionException: HikariPool-4 - Connection is not available, request timed out after 30001ms.
        at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:695)
        at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:197)
        at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162)
        at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
        at org.jetbrains.exposed.sql.Database$Companion$connect$3.invoke(Database.kt:142)
        at org.jetbrains.exposed.sql.Database$Companion$connect$3.invoke(Database.kt:139)
        at org.jetbrains.exposed.sql.Database$Companion$doConnect$3.invoke(Database.kt:127)
        at org.jetbrains.exposed.sql.Database$Companion$doConnect$3.invoke(Database.kt:128)
        at org.jetbrains.exposed.sql.transactions.ThreadLocalTransactionManager$ThreadLocalTransaction$connectionLazy$1.invoke(ThreadLocalTransactionManager.kt:69)
        at org.jetbrains.exposed.sql.transactions.ThreadLocalTransactionManager$ThreadLocalTransaction$connectionLazy$1.invoke(ThreadLocalTransactionManager.kt:68)
        at kotlin.UnsafeLazyImpl.getValue(Lazy.kt:81)
        at org.jetbrains.exposed.sql.transactions.ThreadLocalTransactionManager$ThreadLocalTransaction.getConnection(ThreadLocalTransactionManager.kt:75)
        at org.jetbrains.exposed.sql.Transaction.getConnection(Transaction.kt)
        at org.jetbrains.exposed.sql.statements.InsertStatement.prepared(InsertStatement.kt:157)
        at org.jetbrains.exposed.sql.statements.Statement.executeIn$exposed_core(Statement.kt:47)
        ... 19 common frames omitted
Caused by: org.postgresql.util.PSQLException: Connection to localhost:49544 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
        at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:303)
        at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:51)

I have reported this issue to Ktor team at https://youtrack.jetbrains.com/issue/KTOR-4928 and found that this could be resolved by explicitly setting the db parameter for newSuspendedTransaction function.
So I assumed this could be a bug with newSuspendedTransaction when using implicit db. Please help to verify.

Thanks and regards,
Vinh.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions