LuckPerms

LuckPerms

41.4k Downloads

Mysql - Too many connections

Westus opened this issue ยท 1 comments

commented

Yesterday, on all four servers disconnected database error "Too many connections".
Log test server on which the attack was carried out:

[17:18:12] [Craft Scheduler Thread - 657/INFO]: [Vault] Checking for Updates:
[17:18:12] [Craft Scheduler Thread - 657/WARN]: [Vault] Stable Version: 1.5.6 is out! You are still running version: 1.4.1
[17:18:12] [Craft Scheduler Thread - 657/WARN]: [Vault] Update at: http://dev.bukkit.org/server-mods/vault
[19:08:05] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:11] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:11] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:11] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:11] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:11] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:11] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:11] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:12] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:12] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:12] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:12] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:12] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:12] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:12] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:12] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:13] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:13] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:13] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:13] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:13] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:13] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:13] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:13] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:14] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:08:14] [RCON Listener #1/INFO]: Rcon connection from: /xx.xx.xx.xx
[19:12:15] [Craft Scheduler Thread - 732/WARN]: [Craft Scheduler Thread - 732] WARN com.zaxxer.hikari.pool.PoolBase - luckperms - Failed to validate connection com.mysql.jdbc.JDBC4Connection@3162e700 (Communications link failure

The last packet successfully received from the server was 1,785,449 milliseconds ago.  The last packet sent successfully to the server was 8 milliseconds ago.)

This server plug-ins interact with the database have been established:

  • craftconomy3-3.3
  • LuckPerms-Bukkit-Legacy-2.17.72

At this time on another server 1.10.2 were such errors:

[19:06:09] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:06:11] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[19:06:21] [Server thread/INFO] [nucleus/]: Server ran the command: /list 
[19:06:39] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:06:39] [Server thread/DEBUG] [FML/]: Gathering id map for writing to world save world
[19:06:41] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[19:06:55] [Server thread/INFO] [nucleus/]: Server ran the command: /list 
[19:07:09] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:07:11] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[19:07:24] [Server thread/DEBUG] [FML/]: Gathering id map for writing to world save world
[19:07:29] [Server thread/INFO] [nucleus/]: Server ran the command: /list 
[19:07:39] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:07:41] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[19:08:04] [Server thread/INFO] [nucleus/]: Server ran the command: /list 
[19:08:09] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:08:09] [Server thread/DEBUG] [FML/]: Gathering id map for writing to world save world
[19:08:11] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[19:08:38] [Server thread/INFO] [nucleus/]: Server ran the command: /list 
[19:08:39] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:08:41] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[19:08:54] [Server thread/DEBUG] [FML/]: Gathering id map for writing to world save world
[19:09:09] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:09:11] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[19:09:13] [Server thread/INFO] [nucleus/]: Server ran the command: /list 
[19:09:39] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:09:39] [Server thread/DEBUG] [FML/]: Gathering id map for writing to world save world
[19:09:41] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[19:09:47] [Server thread/INFO] [nucleus/]: Server ran the command: /list 
[19:10:09] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:10:11] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[19:10:21] [Server thread/INFO] [nucleus/]: Server ran the command: /list 
[19:10:24] [Server thread/DEBUG] [FML/]: Gathering id map for writing to world save world
[19:10:39] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:10:41] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[19:10:56] [Server thread/INFO] [nucleus/]: Server ran the command: /list 
[19:11:09] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:11:09] [Server thread/DEBUG] [FML/]: Gathering id map for writing to world save world
[19:11:11] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[19:11:30] [Server thread/INFO] [nucleus/]: Server ran the command: /list 
[19:11:39] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:11:41] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[19:11:42] [pool-2-thread-456/WARN] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Failed to validate connection com.mysql.jdbc.JDBC4Connection@78fa34e6 (Communications link failure

Last packet sent to the server was 22 ms ago.)
[19:11:42] [luckperms connection closer/DEBUG] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Closing connection com.mysql.jdbc.JDBC4Connection@78fa34e6: (connection is evicted or dead)
[19:11:42] [pool-2-thread-456/WARN] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Failed to validate connection com.mysql.jdbc.JDBC4Connection@763dc589 (Communications link failure

Last packet sent to the server was 1 ms ago.)
[19:11:42] [luckperms connection closer/DEBUG] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Closing connection com.mysql.jdbc.JDBC4Connection@763dc589: (connection is evicted or dead)
[19:11:42] [pool-2-thread-456/WARN] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Failed to validate connection com.mysql.jdbc.JDBC4Connection@385c4135 (Communications link failure

Last packet sent to the server was 0 ms ago.)
[19:11:42] [luckperms connection closer/DEBUG] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Closing connection com.mysql.jdbc.JDBC4Connection@385c4135: (connection is evicted or dead)
[19:11:42] [pool-2-thread-456/WARN] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Failed to validate connection com.mysql.jdbc.JDBC4Connection@369ba84e (Communications link failure

Last packet sent to the server was 0 ms ago.)
[19:11:42] [luckperms connection closer/DEBUG] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Closing connection com.mysql.jdbc.JDBC4Connection@369ba84e: (connection is evicted or dead)
[19:11:42] [pool-2-thread-456/WARN] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Failed to validate connection com.mysql.jdbc.JDBC4Connection@4ea2c25b (Communications link failure

Last packet sent to the server was 0 ms ago.)
[19:11:42] [luckperms connection closer/DEBUG] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Closing connection com.mysql.jdbc.JDBC4Connection@4ea2c25b: (connection is evicted or dead)
[19:11:42] [pool-2-thread-456/WARN] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Failed to validate connection com.mysql.jdbc.JDBC4Connection@406535ff (Communications link failure

Last packet sent to the server was 1 ms ago.)
[19:11:42] [luckperms connection closer/DEBUG] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Closing connection com.mysql.jdbc.JDBC4Connection@406535ff: (connection is evicted or dead)
[19:11:42] [pool-2-thread-456/WARN] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Failed to validate connection com.mysql.jdbc.JDBC4Connection@6e579261 (Communications link failure

Last packet sent to the server was 0 ms ago.)
[19:11:42] [luckperms connection closer/DEBUG] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Closing connection com.mysql.jdbc.JDBC4Connection@6e579261: (connection is evicted or dead)
[19:11:42] [pool-2-thread-456/WARN] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Failed to validate connection com.mysql.jdbc.JDBC4Connection@609071db (Communications link failure

Last packet sent to the server was 0 ms ago.)
[19:11:42] [luckperms connection closer/DEBUG] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Closing connection com.mysql.jdbc.JDBC4Connection@609071db: (connection is evicted or dead)
[19:11:42] [pool-2-thread-456/WARN] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Failed to validate connection com.mysql.jdbc.JDBC4Connection@58b47af3 (Communications link failure

Last packet sent to the server was 0 ms ago.)
[19:11:42] [luckperms connection closer/DEBUG] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Closing connection com.mysql.jdbc.JDBC4Connection@58b47af3: (connection is evicted or dead)
[19:11:42] [pool-2-thread-456/WARN] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Failed to validate connection com.mysql.jdbc.JDBC4Connection@56738f95 (Communications link failure

Last packet sent to the server was 0 ms ago.)
[19:11:42] [luckperms connection closer/DEBUG] [com.zaxxer.hikari.pool.PoolBase/luckperms]: luckperms - Closing connection com.mysql.jdbc.JDBC4Connection@56738f95: (connection is evicted or dead)
[19:11:42] [luckperms connection adder/DEBUG] [com.zaxxer.hikari.pool.HikariPool/luckperms]: luckperms - Added connection com.mysql.jdbc.JDBC4Connection@77430d4a
[19:11:54] [Server thread/DEBUG] [FML/]: Gathering id map for writing to world save world
[19:12:05] [Server thread/INFO] [nucleus/]: Server ran the command: /list 
[19:12:09] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:12:11] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=1, active=0, idle=1, waiting=0)
[19:12:11] [luckperms connection adder/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Added connection com.mysql.jdbc.JDBC4Connection@453b0ef2
[19:12:11] [luckperms connection adder/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Added connection com.mysql.jdbc.JDBC4Connection@4bfcf825
[19:12:11] [luckperms connection adder/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Added connection com.mysql.jdbc.JDBC4Connection@4fc36582
[19:12:11] [luckperms connection adder/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Added connection com.mysql.jdbc.JDBC4Connection@ac1f21e
[19:12:11] [luckperms connection adder/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Added connection com.mysql.jdbc.JDBC4Connection@1710312a
[19:12:11] [luckperms connection adder/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Added connection com.mysql.jdbc.JDBC4Connection@3b01de3d
[19:12:11] [luckperms connection adder/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Added connection com.mysql.jdbc.JDBC4Connection@6f3a43aa
[19:12:11] [luckperms connection adder/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Added connection com.mysql.jdbc.JDBC4Connection@6aee0d51
[19:12:11] [luckperms connection adder/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Added connection com.mysql.jdbc.JDBC4Connection@7ce1f847
[19:12:11] [luckperms connection adder/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - After adding stats (total=10, active=0, idle=10, waiting=0)
[19:12:39] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:12:39] [Server thread/INFO] [nucleus/]: Server ran the command: /list 
[19:12:40] [Server thread/DEBUG] [FML/]: Gathering id map for writing to world save world
[19:12:41] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[19:13:09] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/]: HikariPool-1 - Pool stats (total=25, active=1, idle=24, waiting=0)
[19:13:11] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[19:13:14] [Server thread/INFO] [nucleus/]: Server ran the command: /list 

This server has been installed LuckPerms-Sponge-2.17.60

commented

In the second log, "HikariPool-1" refers to another plugin's Hikari pool, and "luckperms" is LP's pool. You can see they're both behaving in similar ways, and also both recovered quickly after the connections were dropped.

You need to raise the max connections setting on your MySQL server, or lower the pool size of "HikariPool-1". (I guess that's craftconomy3). 25 is too many.

Either way, this isn't a LuckPerms issue.