ClusterTopologyMonitorImpl leaks threads

[vvitiesc]

Describe the bug

`"Thread-75817-nm" #271317 daemon prio=5 os_prio=0 cpu=2817.92ms elapsed=1082.59s tid=0x00007fbb144d4000 nid=0x1ff7 sleeping [0x00007fb7e2463000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(java.base@11.0.18/Native Method)
at java.lang.Thread.sleep(java.base@11.0.18/Thread.java:334)
at java.util.concurrent.TimeUnit.sleep(java.base@11.0.18/TimeUnit.java:446)
at software.amazon.jdbc.hostlistprovider.monitoring.ClusterTopologyMonitorImpl$NodeMonitoringThread.run(ClusterTopologyMonitorImpl.java:842)

"Thread-75819-nm" #271429 daemon prio=5 os_prio=0 cpu=2663.22ms elapsed=998.01s tid=0x00007fbad4176800 nid=0x2079 sleeping [0x00007fb7c89ca000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(java.base@11.0.18/Native Method)
at java.lang.Thread.sleep(java.base@11.0.18/Thread.java:334)
at java.util.concurrent.TimeUnit.sleep(java.base@11.0.18/TimeUnit.java:446)
at software.amazon.jdbc.hostlistprovider.monitoring.ClusterTopologyMonitorImpl$NodeMonitoringThread.run(ClusterTopologyMonitorImpl.java:842)

"Thread-75820-nm" #271430 daemon prio=5 os_prio=0 cpu=2662.86ms elapsed=997.99s tid=0x00007fbad4177000 nid=0x207a sleeping [0x00007fb7c4182000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(java.base@11.0.18/Native Method)
at java.lang.Thread.sleep(java.base@11.0.18/Thread.java:334)
at java.util.concurrent.TimeUnit.sleep(java.base@11.0.18/TimeUnit.java:446)
at software.amazon.jdbc.hostlistprovider.monitoring.ClusterTopologyMonitorImpl$NodeMonitoringThread.run(ClusterTopologyMonitorImpl.java:842)

"Thread-75822-nm" #271436 daemon prio=5 os_prio=0 cpu=2553.69ms elapsed=986.91s tid=0x00007fbaf841e000 nid=0x2080 sleeping [0x00007fb7c4a8b000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(java.base@11.0.18/Native Method)
at java.lang.Thread.sleep(java.base@11.0.18/Thread.java:334)
at java.util.concurrent.TimeUnit.sleep(java.base@11.0.18/TimeUnit.java:446)
at software.amazon.jdbc.hostlistprovider.monitoring.ClusterTopologyMonitorImpl$NodeMonitoringThread.run(ClusterTopologyMonitorImpl.java:842)`

after 4 days of loadtesting the JVM using aws-advanced-jdbc-wrapper had 5690 NodeMonitoringThreads in TIMED_WAITING state

Expected Behavior

Expecting the wrapper to not to leak threads

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

failover2,efm2,auroraConnectionTracker, connection params: cachePrepStmts=true&useServerPrepStmts=false&prepStmtCacheSize=1000&useUnicode=true&characterEncoding=UTF-8&connectTimeout=60000&socketTimeout=360000&initializationFailTimeout=30000&maxLifeTime=500000&idleTimeout=300000&useSSL=false

Current Behavior

was loadtesting our software and tests failed due to the new version using considerably more resources that the reference test with same load.

Reproduction Steps

can reproduce this using our app, cannot provide code

Possible Solution

No response

Additional Information/Context

No response

The AWS Advanced JDBC Driver version used

2.5.4

JDK version used

openjdk version "11.0.18" 2023-01-17 LTS OpenJDK Runtime Environment Corretto-11.0.18.10.1 (build 11.0.18+10-LTS) OpenJDK 64-Bit Server VM Corretto-11.0.18.10.1 (build 11.0.18+10-LTS, mixed mode)

Operating System and version

4.14.305-227.531.amzn2.x86_64 #1 SMP Tue Feb 14 09:55:28 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

[sergiyvamz]

Hi @vvitiesc

Thank you for reaching out and raising this issue. We'll take a look at this and keep you updated as we investigate.

[vvitiesc]

This actually could be a prometheus bug, investigating.

[aaron-congo]

Hi @vvitiesc,

Had a few questions:

• are you using the standard writer cluster URL in your load tester? Do you use any other URLs?
• does your load tester trigger failover (I'm assuming yes)?
• how long did you run your load tester for in this instance? You mentioned 4 days; was it running for the entire duration?
• can you give me any more info about the workflow you execute with your connections in the load tester?

[vvitiesc]

Hi @aaron-congo ,

1. using jdbc:aws-wrapper:mysql:// when using aws-advanced-jdbc-wrapper
2. there was no failovers (did failover testing, as a separate thing, and everything went smoothly)
3. this was a 4 days long single load test, app was running for the entire duration
4. load tests are carried out by running load test clients against our appserver, where we experienced the thread leak. Load is write heavy for the database with mixture of compressed blobs and normal relational table updates with some inserts. I'd say at least 70% updates/inserts vs 30% selects.

[aaron-congo]

@vvitiesc thanks for that info, couple more questions:

1. I understand that you are using the jdbc:aws-wrapper:mysql:// protocol, but which URLs are you using? Are you using just the writer cluster URL (eg somedatabase.cluster-xyz.region.rds.amazonaws.com) or are you also using the reader cluster URL (eg somedatabase.cluster-ro-xyz.region.rds.amazonaws.com)?
2. Would you be able to tell me how many instances are in your cluster?

[vvitiesc]

@aaron-congo sure, I'll share what I can:

1. The appserver type where the problem manifested uses a DNS entry which is pointing to the cluster writer endpoint (<db-cluster-identifier>.cluster-<hash>.us-east-1.rds.amazonaws.com). We have such appserver types, which contact to the reader endpoint in similar manner, but those didn't have the problem.
2. Our DB clusters have two instances for failover purposes, most of the queries (99%) are done through the cluster writer endpoint (abc.cluster-<hash>.us-east-1.rds.amazonaws.com)

[hsuamz]

Hello @vvitiesc,

If possible, would you also be able to provide driver trace logs through this workflow? You can also pass this through your AWS TAM and he can forward us the logs if GitHub isn't suitable.

Thanks,

Matthew

[vvitiesc]

@hsuamz don't have trace logs from the previous run. How to enable those for the next time I test with the wrapper?

Have provided some details I have found to our TAM.

[aaron-congo]

Hi @vvitiesc,

Instructions on how to enable logs can be found here. If its possible to reproduce the problem on your side with fewer connections and a shorter run duration that will also help make the logs clearer (eg if the problem still occurs even with a single connection instead of tens/hundreds of connections). But either way, the logs should be helpful. Thanks!

[aaron-congo]

@vvitiesc had some more question:

1. Are all the leaked threads in the TIMED_WAITING state at ClusterTopologyMonitorImpl.java:842? All of the threads in your example above are. That line corresponds to this 100ms sleep; it seems strange that they would all be stuck there even though it is a relatively short sleep.
2. You mentioned this might be related to a prometheus bug, is there github issue or a prometheus bug report you can point me to?
3. In the RDS databases console, is your database cluster engine listed as "Aurora MySQL" or "MySQL Community"? Is it a multi-az deployment?

[sergiyvamz]

Hi @vvitiesc

We've made some changes that we hope can prevent threads leaking. Could you please verify if the latest changes address the issue for you? You can find the latest change in the snapshot build. More information on how to use the snapshot build is available here.
https://github.com/aws/aws-advanced-jdbc-wrapper/blob/main/docs/using-the-jdbc-driver/UsingTheJdbcDriver.md#using-a-snapshot-of-the-driver

[vvitiesc]

Hi @sergiyvamz

Just finished testing with 2.5.6-20250318.161248-12. Did two runs, first 17hours with 2.5.4, which was clearly leaking threads, and then 22hours with the snapshot release.

It seems that the thread leak has been fixed.