Log spam with HikariPool
LemADEC opened this issue ยท 7 comments
Our server logs are spammed with debug details from HikariPool and LuckPerms, for example:
[05:53:15] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:53:32] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
[05:53:32] [Server thread/DEBUG] [FML/]: Gathering id map for writing to world save Teal
[05:53:33] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:53:36] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[05:53:39] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:53:44] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:53:47] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:53:48] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:53:49] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:53:51] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:53:55] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:53:57] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:53:58] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:54:00] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:54:01] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:54:02] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:54:02] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
[05:54:03] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:54:06] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[05:54:11] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:54:17] [Server thread/DEBUG] [FML/]: Gathering id map for writing to world save Teal
[05:54:22] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:54:32] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:54:32] [HikariPool-1 housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
[05:54:33] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:54:36] [luckperms housekeeper/DEBUG] [com.zaxxer.hikari.pool.HikariPool/sponge]: luckperms - Pool stats (total=10, active=0, idle=10, waiting=0)
[05:54:37] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:54:42] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:54:46] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:54:49] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:54:52] [Thread-26/DEBUG] [com.zaxxer.hikari.pool.PoolBase/sponge]: HikariPool-1 - Reset (autoCommit) on connection org.mariadb.jdbc.MariaDbConnection@235a74f9
[05:55:00] [Server thread/INFO] [nucleus/]: Server ran the command: /weather Teal clear
Over 3h40m of runtime (ServerStarted to ServerStopped), we've 20221 lines, including:
- 4674 lines about "HikariPool-1 - "
- 877 lines about "luckperms - Pool stats"
That's ~27% of log lines
This was observed with
forge-1.10.2-12.18.3.2202-universal.jar
spongeforge-1.10.2-2202-5.1.0-BETA-2020.jar
LuckPerms-Sponge-2.16.79.jar
Full log is here: https://gist.github.com/LemADEC/ac2f6b751f5d68724344b583bdea7451
As far as I can tell, it's not possible to set SLF4J's logging level at runtime.
You could try using these startup flags to suppress logs from "com.zaxxer.hikari".
https://stackoverflow.com/questions/14544991/how-to-configure-slf4j-simple
http://slf4j.42922.n3.nabble.com/How-to-programmatically-set-log-level-in-SLF4J-td45652.html
https://stackoverflow.com/questions/27274115/disable-hikaripool-logging
However, I've spent a good ~20 mins testing and can't get it to work for me.
Either way, this isn't really an LP issue. More of an issue with Forge's logging setup. (you'll notice that these entries do not get sent to the console.)
You need to override FML configuration https://github.com/MinecraftForge/FML/blob/master/src/main/resources/log4j2.xml by copying it to your launch folder,
then adding a specific logger for HikariCP at error level
...
<logger name="com.zaxxer.hikari">
<level value="error"/>
</logger>
...
and forcing your custom configuration file through your launcher parameter
-Dlog4j.configurationFile=log4j2.xml
This is as explained briefly on FML and SpongeCommon issues here: MinecraftForge/MinecraftForge#1643
and there: SpongePowered/Sponge#281
Not sure how that would be possible in LuckPerms? I just download the Hikari jar and load it. How would the logger implementation know to read from a file in the LP jar?