The wrapper accumulates DB connections that are not being released

[weronkagolonka]

Describe the bug

The plugins at version 2.6.3 seem to aggressively allocate database connections and do not release them.

Expected Behavior

Downgrading to 2.6.1 results in a stable behaviour, where the application's DB user allocates a constant number of connections that does not grow over time.

What plugins are used? What other connection properties were set?

failover,efm2

Current Behavior

After upgrading from 2.6.1 to 2.6.3, the RDS Aurora instance is being flooded with idle connections. When restarting the application, the connection count drops down to pool size * number of pods and it immediately starts growing. Throughout the day the number of connections spike almost up to maximum (for our instance it's 401 connections), disallowing other components to connect and overloading the database.

Nothing has been changed in the application code or the configuration, only the library version has been upgraded.

JDBC driver debug logs did not show anything apart from numerous connection openings. Turning on debug logs on HikarciCP did not reveal any leaks, the housekeeper logged only the configured pool size of 3 connections.

The application itself is a Kotlin-based API service that connects to the database via HikariCP datasource. The connections accumulate despite no API traffic. Here's our configuration:

val hikariConfig = HikariConfig()

hikariConfig.jdbcUrl = "jdbc:aws-wrapper:postgresql://<rds_host>:5432/<db_name>"
hikariConfig.driverClassName = "software.amazon.jdbc.Driver"
hikariConfig.username = "<username>"
hikariConfig.password = "<password>"
hikariConfig.maximumPoolSize = 3
hikariConfig.exceptionOverrideClassName = "software.amazon.jdbc.util.HikariCPSQLException"

val dataSourceProperties = Properties()
dataSourceProperties.setProperty("wrapperPlugins", "failover, efm2")

hikariConfig.dataSourceProperties = dataSourceProperties

database - Aurora PostgreSQL, one instance of size db.t3.medium, engine version 14.9. Maximum number of connections - 401.

Inspecting the activities from the DB user accumulating the connections revealed that all of them only perform health checks:

<db_name>=> SELECT LEFT(query, 200) AS query
FROM pg_stat_activity
WHERE usename = '<username>'
ORDER BY backend_start DESC;

| query                                                                                                                                                                                                                                                                                                                  |
|------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------|
| SELECT SERVER_ID, CASE WHEN SESSION_ID = 'MASTER_SESSION_ID' THEN TRUE ELSE FALSE END, CPU, COALESCE(REPLICA_LAG_IN_MSEC, 0), LAST_UPDATE_TIMESTAMP FROM aurora_replica_status() WHERE EXTRACT(EPOCH FROM(NOW() - LAST_UPDATE_TIMESTAMP)) <= 300 OR SESSION_ID = ' MASTER_SESSION_ID' OR LAST_UPDATE_TIMESTAMP IS NULL |
...

In the graph below, you can see the connection growth after each application restart. Yesterday, the library has been downgraded and the connections dropped to a stable number, where the slight spikes are performed by a lambda function that connects to the database via RDS proxy:

Reproduction Steps

Reproduction requires starting up a JVM application that connects to the Aurora PostgreSQL database via HikariCP middleware with AWS Advanced JDBC wrapper configured as in the field above. In our case it took >20 hours to reach over 390 connections.

Possible Solution

No response

Additional Information/Context

No response

The AWS Advanced JDBC Driver version used

2.6.3

JDK version used

21

Operating System and version

Linux

[aaron-congo]

Hi @weronkagolonka

Thank you for reporting this issue. I have been unable to reproduce this problem so far. Are you able to provide a simple sample app that reproduces the problem? Also, are you able to provide logs for the problem? Information for logging can be found here

[weronkagolonka]

Thank you for a quick response. I'll try to come up with an example app in the upcoming days.

[aaron-congo]

Hi @weronkagolonka, we have received reports of this problem from others as well but still have not been able to reproduce it. If you can provide a sample app that reproduces it that would be great. In the meantime we had some questions for you that might help us in our own efforts to reproduce.

1. Are you able to supply logs for the problem?
2. Are you able to supply any sample code?
3. Did you encounter the problem before or after the application restarts? We are trying to determine if one of the factors that triggers the bug is a network disruption.
4. Are you using Spring, Spring Boot, JPA, or any other frameworks that might be relevant?
5. You mentioned that after restart the number of connections jumps down to pool size * number of pods, by number of pods do you mean number of connection pools? I see your maximum pool size for the hikari config is 3; how many connection pods/pools are you creating when you encounter this problem?
6. Roughly how many connections are executing statements concurrently at a given time?
7. Roughly how long do your SQL statements execute for? Do they finish quickly or are they more complex/intensive?
8. Is there any other generic info that you can tell me about what your application does so that I have a greater chance of reproducing the issue?

[REDAPG]

Just to say that v2.6.4 is also showing this and moving back to v2.6.1 stops this. (thanks for that!) This is my config

wrapperPlugins=auroraConnectionTracker,failover2,dataCache,efm2&connectTimeout=10000&socketTimeout=5000&loginTimeout=10000&tcpKeepAlive=false&monitoring-connectTimeout=10000&monitoring-socketTimeout=5000&wrapperLogUnclosedConnections=true&wrapperDialect=aurora-mysql&wrapperTargetDriverDialect=mysql-connector-j

This is part of the connectionURL for the datasource within Jboss EAP 7.4.23 (so connection pool managed by JBoss)

[weronkagolonka]

@aaron-congo Thanks for the update and sorry for not providing any examples but I just couldn't find any spare time to have a closer look into this. I'll try to answer your questions for now:

1. In the "real" applications, there weren't really any logs indicating the problem. The way I discovered the issue was that our lambda function (connecting via RDS proxy) could not progress and terminated at the very start due to lack of available connections. Enabling debug logs on HikariCP connection pool as well as the JDB wrapper did not show anything useful, apart from regular housekeeping logs - the HikariCP pool continuously reported only 3 connections allocated (i.e. the number configured). The wrapper logs only showed info regarding new connections. Although I'll have a closer look at that when building the example.
2. As mentioned above, I'll try to do that in my spare time, last weeks were very busy.
3. To add more context, we run our applications in Kubernetes. The issue started after I deployed to pre-prod environment, and the deployment contained some dependency updates, including JDBC wrapper at 2.6.3, so yes, there was a restart of the pods. The number on allocated connections grew to >390 in a course of ~20 hours and the issue was discovered when attempting to run the lambda the next day. In lower environments, the issue was not discovered earlier because we shut down our machines at night and on the weekends, so the number of connections was dropping every morning. So to answer your question - the restart has an impact in the sense that it "cleans up" the connections just to start allocating soon. The application itself did not restart on its own due to this issue, they were operating normally using connections allocated by HikariCP.
4. No framework, the app is a Kotlin-based REST API server built with http4k library. For the database, it uses HikariCP data source and JetBrain's exposed`library for querying and transaction handling.
5. I wasn't very clear there - I meant Kubernetes pods. We configured Hikari to allocate connections according to the formula they recommended, i.e. no. of CPU cores * 2 + 1. The application's container uses 1 CPU core, so it should allocate 3 connections, plus the deployment is configured to have 2 replicas, thus 2 pods allocating 3 connections each. So the expected number of connections when deploying the application, based on HikariCP config only, is 6. I found in other issues here in the repo that the wrapper allocates some connections on its own for monitoring, so I figured that 6 + few extra connections should be expected (correct me if I'm wrong). Last time I tested, and after tuning the connection pool sizes to the mentioned formula, the application was starting with 10 allocated connections, so each pod was allocating 1-3 more connections that what was specified in Hikari config. As time passed by, the connections were just growing.
6. One, up to 2 connections are used when running tests that extensively query the API service in parallel (over 500 cases). The test takes around 4-5 minutes.
7. We don't have any long-running queries, just basic CRUD operations that often require joining multiple tables. I've just run the mentioned test suite and checked http_server_request_latency_seconds_max (so the overall time for the whole http request), and the highest duration is 0.4-0.45 seconds, similar values are observed in Kubernetes for the last 30 days.
8. For the sample, I am planning to build a simple http4k application connecting to the database with HikariCP connection pool and using AWD JDBC wrapper in the data source. Perhaps will try adding one http route that would spin up a transaction via exposed and send some queries, but based on the behaviour observed it shouldn't really matter as increasing load on the application did not impact the connection number. So far the testing consisted of deploying the application (which cleaned up the connections), and pretty much waiting a whole day and observing the connection growth.

I hope these answers will give you a little bit more context until I come up with something reproducible.

[aaron-congo]

Hi @weronkagolonka, thanks for your response. Unfortunately I still have not been able to reproduce the problem. Is it easy for you to test whether this bug appears in your own environment? We recently released a new version of the driver and are curious if it resolves this issue or not (2.6.5).

[grahamattentive]

We just saw this same issue exactly connecting to an Aurora Postgres cluster. It occurred for both reader and writer connections. We are on 2.6.5 and using failoverV2, efm2, and auroraConnectionTracker. In our case the app ate up a ton of connections very quickly though, it didn't grow slowly over time.

[sergiyvamz]

Hi @grahamattentive

Thank you for informing us that this is still ongoing issue. We'd be happy to troubleshoot the issue. Could you please help us to reproduce the issue?

• You mentioned that connections build up quickly. Can you give some numbers? How many connections added up and for what interval of time?
• What is the driver configuration used in your application (connection string, configuration parameters)?
• What kind of host url do you use in connection string? Is it cluster writer endpoint? Cluster reader endpoint? Cluster custom endpoint? Any other?
• Do you use RDS Proxy?
• Do you use connection pool? What is configuration of connection pool in your application?
• Can you provide logs with TRACE/FINEST level?
• Could you provide a simple app that reproduce the issue?

Thank you!

[aaron-congo]

Hi @grahamattentive,

Just following up to the questions posted above. We would like to figure out what the issue is but have been having trouble reproducing, so any info you can give us would be much appreciated. Thanks!

[fgaule]

@aaron-congo hope this helps to reproduce the issue:

Environment

• Connection Pool: com.zaxxer:HikariCP:4.0.3

• JDBC Wrapper:

  <dependency>
      <groupId>software.amazon.jdbc</groupId>
      <artifactId>aws-advanced-jdbc-wrapper</artifactId>
      <version>2.6.5</version>
  </dependency>

• Database: * AWS Mysql 8

---

HikariCP Configuration

pool_connection:
  maximum-pool-size: 50
  minimum-idle: 5
  idle-timeout: 15000       # 15s
  max-lifetime: 30000       # 30s
  connection-timeout: 2000  # 2s
  transaction-isolation: TRANSACTION_READ_COMMITTED
  leak-detection-threshold: 5000

Driver Configuration

db:
  driver-class-name: software.amazon.jdbc.Driver
  obtain-lock-timeout: 1000
  parameters:
    cachePrepStmts: true
    prepStmtCacheSize: 250
    prepStmtCacheSqlLimit: 2048
    useServerPrepStmts: true
    rewriteBatchedStatements: true
    useLocalSessionState: true

---

Description

We are observing unexpected connection pooling behavior when using the AWS Advanced JDBC Wrapper together with HikariCP.

The connection pool occasionally reaches its maximum size and fails to release connections properly, even under moderate traffic.

[h42-carlopelliccia]

I can confirm that I’m experiencing the same issue. My setup is HikariCP connecting to Postgres Aurora RDS. I started noticing the problem after upgrading from version 2.3.7 to 2.6.0, and it got worse when moving to the latest 2.6.6. For now, I’ve reverted back to 2.3.7, because 2.6.0 also suffers from the issue, although it seems to a lesser extent.

The first spike occurred with version 2.6.0. So I upgraded to 2.6.6 and restarted, but the connections began increasing much more rapidly, so I stopped it and went back to 2.6.0 for a short while, and finally to 2.3.7. Since reverting to 2.3.7, they haven’t started rising again and have stayed at very low numbers.

[aaron-congo]

Hi @weronkagolonka, I think I have been able to reproduce this issue, but only when including the failover2 plugin specifically. It looks like most people on this issue are using that plugin. However, it looks like you are using failover1, since your wrapperPlugins settings uses the plugin code "failover" instead of "failover2". I just wanted to double check that you are indeed seeing this issue without the failover2 plugin?

[aaron-congo]

@REDAPG and @grahamattentive, since you are using the failover2 plugin and I have been able to reproduce with that plugin, can you please try setting the "clusterId" property to "1" in your tests and let me know if it resolves the issue or not? Also, can you please let me know what kind of URL you are seeing the problem with (writer cluster, reader cluster, custom cluster, instance URL, or rds proxy etc)?

@fgaule and @h42-carlopelliccia, can you please let me know which wrapperPlugins you are using and what kind of URL you are seeing the problem with (writer cluster, reader cluster, custom cluster, instance URL, or rds proxy etc)? If you are using the failover2 plugin, you can also try testing with the "clusterId" property to "1" and please let me know if it resolves the issue or not