Getting CompletionException after almost every player join

[JustBru00]

Describe the issue

Almost every time players join, a SQL Failure is reported.
This network is using the same MySQL database for the proxy and all servers.

Exceptions & Other Logs

82d37f2caa - Last occurred: 2025-02-23 Occurrences: 2
---- Context 2 ----
Plan v5.6 build 2965
Velocity 3.4.0-SNAPSHOT (git-f986eb51-b472)
Server v3.4.0-SNAPSHOT (git-f986eb51-b472)

Transaction: class com.djrapitops.plan.extension.implementation.storage.transactions.results.StorePlayerGroupsResultTransaction
DB State: OPEN - fatal: false
Error code: 1205
DELETE FROM plan_extension_groups WHERE uuid=? AND provider_id=(SELECT id FROM plan_extension_providers WHERE name=? AND plugin_id=(SELECT id FROM plan_extension_plugins WHERE name=? AND server_uuid=? LIMIT 1) LIMIT 1)
Unknown SQL Error code

---- Context 1 ----
Plan v5.6 build 2965
Velocity 3.4.0-SNAPSHOT (git-f986eb51-b472)
Server v3.4.0-SNAPSHOT (git-f986eb51-b472)

Transaction: class com.djrapitops.plan.extension.implementation.storage.transactions.results.StorePlayerGroupsResultTransaction
DB State: OPEN - fatal: false
Error code: 1205
DELETE FROM plan_extension_groups WHERE uuid=? AND provider_id=(SELECT id FROM plan_extension_providers WHERE name=? AND plugin_id=(SELECT id FROM plan_extension_plugins WHERE name=? AND server_uuid=? LIMIT 1) LIMIT 1)
Unknown SQL Error code

---- Stacktrace ----
java.util.concurrent.CompletionException: com.djrapitops.plan.exceptions.database.DBOpException: SQL Failure: Lock wait timeout exceeded; try restarting transaction
   java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:315)
   java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:320)
   java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1770)
   java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
   java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
   java.base/java.lang.Thread.run(Thread.java:1583)
Caused by:
com.djrapitops.plan.exceptions.database.DBOpException: SQL Failure: Lock wait timeout exceeded; try restarting transaction
   com.djrapitops.plan.exceptions.database.DBOpException.forCause(DBOpException.java:153)
   com.djrapitops.plan.storage.database.transactions.ExecStatement.execute(ExecStatement.java:57)
   com.djrapitops.plan.storage.database.transactions.Transaction.execute(Transaction.java:223)
   com.djrapitops.plan.extension.implementation.storage.transactions.results.StorePlayerGroupsResultTransaction.performOperations(StorePlayerGroupsResultTransaction.java:59)
   com.djrapitops.plan.storage.database.transactions.Transaction.executeTransaction(Transaction.java:89)
   com.djrapitops.plan.storage.database.SQLDB.lambda$executeTransaction$4(SQLDB.java:374)
   com.djrapitops.plan.storage.database.DBAccessLock.performDatabaseOperation(DBAccessLock.java:78)
   com.djrapitops.plan.storage.database.DBAccessLock.performDatabaseOperation(DBAccessLock.java:56)
   com.djrapitops.plan.storage.database.SQLDB.lambda$executeTransaction$5(SQLDB.java:373)
   java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1768)
   java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
   java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
   java.base/java.lang.Thread.run(Thread.java:1583)
Caused by:
com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction
   com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:115)
   com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:114)
   com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:988)
   com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdateInternal(ClientPreparedStatement.java:1166)
   com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdateInternal(ClientPreparedStatement.java:1101)
   com.mysql.cj.jdbc.ClientPreparedStatement.executeLargeUpdate(ClientPreparedStatement.java:1467)
   com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdate(ClientPreparedStatement.java:1084)
   plan.com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61)
   plan.com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java)
   com.djrapitops.plan.storage.database.transactions.ExecStatement.callExecute(ExecStatement.java:70)
   com.djrapitops.plan.storage.database.transactions.ExecStatement.execute(ExecStatement.java:64)
   com.djrapitops.plan.storage.database.transactions.ExecStatement.execute(ExecStatement.java:55)
   com.djrapitops.plan.storage.database.transactions.Transaction.execute(Transaction.java:223)
   com.djrapitops.plan.extension.implementation.storage.transactions.results.StorePlayerGroupsResultTransaction.performOperations(StorePlayerGroupsResultTransaction.java:59)
   com.djrapitops.plan.storage.database.transactions.Transaction.executeTransaction(Transaction.java:89)
   com.djrapitops.plan.storage.database.SQLDB.lambda$executeTransaction$4(SQLDB.java:374)
   com.djrapitops.plan.storage.database.DBAccessLock.performDatabaseOperation(DBAccessLock.java:78)
   com.djrapitops.plan.storage.database.DBAccessLock.performDatabaseOperation(DBAccessLock.java:56)
   com.djrapitops.plan.storage.database.SQLDB.lambda$executeTransaction$5(SQLDB.java:373)
   java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1768)
   java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
   java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
   java.base/java.lang.Thread.run(Thread.java:1583)
   java.base/java.lang.Thread.getStackTrace(Thread.java:2451)
   com.djrapitops.plan.storage.database.SQLDB.executeTransaction(SQLDB.java:360)
   com.djrapitops.plan.extension.implementation.providers.gathering.DataValueGatherer.storePlayerGroups(DataValueGatherer.java:607)
   com.djrapitops.plan.extension.implementation.providers.gathering.DataValueGatherer.lambda$gatherPlayer$19(DataValueGatherer.java:382)
   java.base/java.util.Optional.ifPresent(Optional.java:178)
   com.djrapitops.plan.extension.implementation.providers.gathering.DataValueGatherer.gatherPlayer(DataValueGatherer.java:382)
   com.djrapitops.plan.extension.implementation.providers.gathering.DataValueGatherer.tryToUpdateValues(DataValueGatherer.java:344)
   com.djrapitops.plan.extension.implementation.providers.gathering.DataValueGatherer.updateValues(DataValueGatherer.java:331)
   com.djrapitops.plan.extension.ExtensionSvc.updatePlayerValues(ExtensionSvc.java:181)
   com.djrapitops.plan.extension.implementation.CallerImplementation.lambda$updatePlayerData$0(CallerImplementation.java:53)
   com.djrapitops.plan.processing.Processing.lambda$submitNonCritical$1(Processing.java:85)
   java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1768)
   java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
   java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
   java.base/java.lang.Thread.run(Thread.java:1583)

Plugin versions

Additional information

[BlueFyreMatt]

I'm also getting the same "Lock wait timeout exceeded; try restarting transaction" error whilst Plan performs various tasks, sounds like a similar setup with Plan operating on Velocity under one MySQL database. Most errors seem to be in relation to extensions. All errors detailed in below links:

CompletionException cb8b5253e8 - https://mclo.gs/n2NCN4J - Occurrences: 1
CompletionException b6869ad6af - https://mclo.gs/IBYQC7d - Occurrences: 5
CompletionException 9d5a4e4d32 - https://mclo.gs/dCpBIJM - Occurrences: 9
CompletionException 16e5b4499c - https://mclo.gs/o5492yc - Occurrences: 3
CompletionException 220b4da0bb - https://mclo.gs/k8YaEQd - Occurrences: 63
CompletionException 4c1756436a - https://mclo.gs/TCZfSmr - Occurrences: 2
DataExtensionMethodCallException c3c5452ede - https://mclo.gs/Txw7QKM - Occurrences: 1
CompletionException 71881bf826 - https://mclo.gs/FNgDg1l - Occurrences: 18
CompletionException 433c453a81 - https://mclo.gs/cOZBAVV - Occurrences: 3
CompletionException 9c7af7089e - https://mclo.gs/vjJwyQb - Occurrences: 33
CompletionException f6c6981ce1 - https://mclo.gs/2IKYzLT - Occurrences: 14

@JustBru00 Since our setups are so similar and both issues are related to extensions, I wondered if you would share your plugins list so we can perhaps narrow down a problematic extension?

[AuroraLS3]

I think solving this might need some kind of pooling of the storage of this data so that it's not individual transactions for single data points but batches. - Unfortunately that's quite complicated so it might take a while for this to be fixed.