Description

We have a serious with the last few releases of LuckPerms:

If the database server was unreachable for longer than a few seconds (most likely some network issues in the data center where the host is located), LuckPerms did behave odd multiple times: The table 'luckperms_user_permissions' had got inserted the same record over and over again.

After the network issues were over, LuckPerms didn't recover itself from that and made many of the log entries like these you find in the "log"-box below while flooding the database in background.

LuckPerms did some strange load/locking to the tables so we were unable to interact with the affected table until we stopped
LuckPerms manually. At this time, that table had grown up to 4GB.

After we recovered the whole database from a backup, the servers were working again.

It almost crashed our network and made it unjoinable.

System configuration (we have a bigger network):

• Multiple instances of Waterfall (recent version, all of them except one share the same host)
• Multiple instances of Paper (we're still on 1.19.3, distributed across a handful of hosts)
• We use ViaVersion and ViaBackward
• The affected MySQL database server is running on a separate host

We've running LuckPerms on Paper too. But these don't share the database with the BungeeCord version and with the Paper one, we didn't have any issues so far, except a few minor ones due to the connectivity issues itself.

We never had such massive issues like this with LuckPerms.

Please fix this. It happened multiple times.

Versions which ran into these troubles:
LuckPerms-Bungee-5.4.71.jar
LuckPerms-Bungee-5.4.84.jar
LuckPerms-Bungee-5.4.98.jar

Reproduction Steps

I was not able to reproduce it so far :(.

Expected Behaviour

LuckPerms shouldn't flood its own database by inserting the same record over and over again after it recovers from a network failure.

Server Details

waterfall-1.20-536.jar

LuckPerms Version

Multiple. See description

Logs and Configs

[21:45:50] [LuckPerms Pool Thread #2/ERROR]: java.sql.SQLTransientConnectionException: luckperms-hikari - Connection is not available, request timed out after 5000ms.
[21:45:50] [LuckPerms Pool Thread #2/ERROR]: at me.lucko.luckperms.lib.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:696)
[21:45:50] [LuckPerms Pool Thread #2/ERROR]: at me.lucko.luckperms.lib.hikari.pool.HikariPool.getConnection(HikariPool.java:197)
[21:45:50] [LuckPerms Pool Thread #2/ERROR]: at me.lucko.luckperms.lib.hikari.pool.HikariPool.getConnection(HikariPool.java:162)
[21:45:50] [LuckPerms Pool Thread #2/ERROR]: at me.lucko.luckperms.lib.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
[21:45:50] [LuckPerms Pool Thread #2/ERROR]: at me.lucko.luckperms.common.storage.implementation.sql.connection.hikari.HikariConnectionFactory.getConnection(HikariConnectionFactory.java:174)
[21:45:50] [LuckPerms Pool Thread #2/ERROR]: at me.lucko.luckperms.common.messaging.sql.SqlMessenger.getConnection(SqlMessenger.java:85)
[21:45:50] [LuckPerms Pool Thread #2/ERROR]: at me.lucko.luckperms.common.messaging.sql.AbstractSqlMessenger.pollMessages(AbstractSqlMessenger.java:115)
[21:45:50] [LuckPerms Pool Thread #2/ERROR]: at net.md_5.bungee.scheduler.BungeeTask.run(BungeeTask.java:66)
[21:45:50] [LuckPerms Pool Thread #2/ERROR]: at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
[21:45:50] [LuckPerms Pool Thread #2/ERROR]: at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[21:45:50] [LuckPerms Pool Thread #2/ERROR]: at java.base/java.lang.Thread.run(Thread.java:833)

[22:03:32] [Netty Worker IO Thread #10/WARN] [LuckPerms]: A permission check was made for player XXXXXX - XXXXXXXX, but LuckPerms does not have any permissions data loaded for them. Perhaps their UUID has been altered since login?
java.lang.Exception: null
at me.lucko.luckperms.bungee.listeners.BungeePermissionCheckListener.onPlayerPermissionCheck(BungeePermissionCheckListener.java:67) ~[?:?]
at jdk.internal.reflect.GeneratedMethodAccessor19.invoke(Unknown Source) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
at net.md_5.bungee.event.EventHandlerMethod.invoke(EventHandlerMethod.java:19) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at net.md_5.bungee.event.EventBus.post(EventBus.java:50) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at net.md_5.bungee.api.plugin.PluginManager.callEvent(PluginManager.java:467) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at net.md_5.bungee.UserConnection.hasPermission(UserConnection.java:600) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at me.SamikCz.PluginsDis.PlayerListener.onTab(PlayerListener.java:32) ~[?:?]
at jdk.internal.reflect.GeneratedMethodAccessor26.invoke(Unknown Source) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
at net.md_5.bungee.event.EventHandlerMethod.invoke(EventHandlerMethod.java:19) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at net.md_5.bungee.event.EventBus.post(EventBus.java:50) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at net.md_5.bungee.api.plugin.PluginManager.callEvent(PluginManager.java:467) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at net.md_5.bungee.connection.UpstreamBridge.handle(UpstreamBridge.java:246) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at net.md_5.bungee.protocol.packet.TabCompleteRequest.handle(TabCompleteRequest.java:87) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at net.md_5.bungee.netty.HandlerBoss.channelRead(HandlerBoss.java:114) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:103) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:103) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:103) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:103) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:800) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:499) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:397) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[waterfall-1.20-536.jar:git:Waterfall-Bootstrap:1.20-R0.1-SNAPSHOT:ec41547:536]
at java.lang.Thread.run(Thread.java:833) [?:?]

Extra Details

I think it has something to do with 1.20 update since we're still on 1.19.3.

Might be something we can resolve with transactions - but without being able to reproduce it's going to be difficult to validate that it has actually fixed the problem.

I'm inclined to suggest that you just re-open this issue if it happens again. SQL statement logging would also be useful