ORMLite ResultSet closed Exception
AdnanMI opened this issue · 19 comments
This happened when people started to join after a restart however the plugin seems to work straight after.
[22:50:51] [Craft Scheduler Thread - 25/WARN]: Exception in thread "Craft Scheduler Thread - 25"
[22:50:51] [Craft Scheduler Thread - 25/WARN]: org.apache.commons.lang.UnhandledException: Plugin BanManager v5.8.0 generated an exception while executing task 5064
at org.bukkit.craftbukkit.v1_8_R3.scheduler.CraftAsyncTask.run(CraftAsyncTask.java:56)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.IllegalStateException: Errors getting more results of class me.confuser.banmanager.data.PlayerNoteData
at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNext(SelectIterator.java:103)
at me.confuser.banmanager.listeners.JoinListener$1.run(JoinListener.java:204)
at org.bukkit.craftbukkit.v1_8_R3.scheduler.CraftTask.run(CraftTask.java:71)
at org.bukkit.craftbukkit.v1_8_R3.scheduler.CraftAsyncTask.run(CraftAsyncTask.java:53)
... 3 more
Caused by: java.sql.SQLException: Operation not allowed after ResultSet closed
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1073)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:982)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:927)
at com.mysql.jdbc.ResultSetImpl.checkClosed(ResultSetImpl.java:794)
at com.mysql.jdbc.ResultSetImpl.next(ResultSetImpl.java:7145)
at me.confuser.banmanager.internal.hikari.pool.HikariProxyResultSet.next(HikariProxyResultSet.java)
at me.confuser.banmanager.internal.ormlite.jdbc.JdbcDatabaseResults.next(JdbcDatabaseResults.java:64)
at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNextThrow(SelectIterator.java:81)
at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNext(SelectIterator.java:98)
... 6 more
This is definitely an issue with ormlite, I'll poke around their code base and see if I can find the cause.
Hey, my server crashed today and yesterday. Error: http://pastebin.ubuntu.com/15190171/
[18:00:38] [Hikari housekeeper (pool HikariPool-0)/WARN]: 46822402 [Hikari housekeeper (pool HikariPool-0)] WARN me.confuser.banmanager.internal.hikari.pool.HikariPool - HikariPool-0 - Unusual system clock change detected, soft-evicting connections from pool.
Maybe you should not adjust your clock while running your Minecraft server ^^
Something definitely changed the system time, which caused Hikari to close all connections. Are you running NTP? Might with worth checking your syslog on the server.
I've not had any more reports of this being a problem since switching to Hikari. Is anyone still experiencing this with v5.9+?
Confirmed.
[17:29:09 WARN]: Exception in thread "Craft Scheduler Thread - 661"
[17:29:09 WARN]: org.apache.commons.lang.UnhandledException: Plugin BanManager v5.9.0 generated an exception while executing task 1780056
at org.bukkit.craftbukkit.v1_8_R3.scheduler.CraftAsyncTask.run(CraftAsyncTask.java:56)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.IllegalStateException: Errors getting more results of class me.confuser.banmanager.data.PlayerNoteData
at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNext(SelectIterator.java:103)
at me.confuser.banmanager.listeners.JoinListener$1.run(JoinListener.java:204)
at org.bukkit.craftbukkit.v1_8_R3.scheduler.CraftTask.run(CraftTask.java:71)
at org.bukkit.craftbukkit.v1_8_R3.scheduler.CraftAsyncTask.run(CraftAsyncTask.java:53)
... 3 more
Caused by: java.sql.SQLException: Operation not allowed after ResultSet closed
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1073)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:982)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:927)
at com.mysql.jdbc.ResultSetImpl.checkClosed(ResultSetImpl.java:794)
at com.mysql.jdbc.ResultSetImpl.next(ResultSetImpl.java:7145)
at me.confuser.banmanager.internal.hikari.pool.HikariProxyResultSet.next(HikariProxyResultSet.java)
at me.confuser.banmanager.internal.ormlite.jdbc.JdbcDatabaseResults.next(JdbcDatabaseResults.java:64)
at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNextThrow(SelectIterator.java:81)
at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNext(SelectIterator.java:98)
... 6 more
[17:29:11 WARN]: 43357765 [HikariPool-0 housekeeper] WARN me.confuser.banmanager.internal.hikari.pool.ProxyLeakTask - Connection leak detection triggered for com.mysql.jdbc.JDBC4Connection@616396b, stack trace follows
[17:29:11 WARN]: java.lang.Exception: Apparent connection leak detected
[17:29:11 WARN]: at me.confuser.banmanager.internal.ormlite.jdbc.DataSourceConnectionSource.getReadWriteConnection(DataSourceConnectionSource.java:120)
[17:29:11 WARN]: at me.confuser.banmanager.internal.ormlite.jdbc.DataSourceConnectionSource.getReadOnlyConnection(DataSourceConnectionSource.java:102)
[17:29:11 WARN]: at me.confuser.banmanager.internal.ormlite.stmt.StatementExecutor.buildIterator(StatementExecutor.java:243)
[17:29:11 WARN]: at me.confuser.banmanager.internal.ormlite.dao.BaseDaoImpl.createIterator(BaseDaoImpl.java:964)
[17:29:11 WARN]: at me.confuser.banmanager.internal.ormlite.dao.BaseDaoImpl.iterator(BaseDaoImpl.java:533)
[17:29:11 WARN]: at me.confuser.banmanager.internal.ormlite.dao.BaseDaoImpl.iterator(BaseDaoImpl.java:528)
[17:29:11 WARN]: at me.confuser.banmanager.internal.ormlite.stmt.QueryBuilder.iterator(QueryBuilder.java:389)
[17:29:11 WARN]: at me.confuser.banmanager.internal.ormlite.stmt.Where.iterator(Where.java:538)
[17:29:11 WARN]: at me.confuser.banmanager.storage.PlayerNoteStorage.getNotes(PlayerNoteStorage.java:45)
[17:29:11 WARN]: at me.confuser.banmanager.listeners.JoinListener$1.run(JoinListener.java:199)
[17:29:11 WARN]: at org.bukkit.craftbukkit.v1_8_R3.scheduler.CraftTask.run(CraftTask.java:71)
[17:29:11 WARN]: at org.bukkit.craftbukkit.v1_8_R3.scheduler.CraftAsyncTask.run(CraftAsyncTask.java:53)
[17:29:11 WARN]: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[17:29:11 WARN]: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[17:29:11 WARN]: at java.lang.Thread.run(Thread.java:745)
Isn't it the same...I guess?
[21:47:47 WARN]: Exception in thread "Craft Scheduler Thread - 1090"
[21:47:47 WARN]: org.apache.commons.lang.UnhandledException: Plugin BanManager v5.9.0 generated an exception while executing task 3533687
at org.bukkit.craftbukkit.v1_8_R3.scheduler.CraftAsyncTask.run(CraftAsyncTask.java:56)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.IllegalStateException: Errors getting more results of class me.confuser.banmanager.data.PlayerWarnData
at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNext(SelectIterator.java:103)
at me.confuser.banmanager.listeners.JoinListener$1.run(JoinListener.java:236)
at org.bukkit.craftbukkit.v1_8_R3.scheduler.CraftTask.run(CraftTask.java:71)
at org.bukkit.craftbukkit.v1_8_R3.scheduler.CraftAsyncTask.run(CraftAsyncTask.java:53)
... 3 more
Caused by: java.sql.SQLException: Operation not allowed after ResultSet closed
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1073)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:982)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:927)
at com.mysql.jdbc.ResultSetImpl.checkClosed(ResultSetImpl.java:794)
at com.mysql.jdbc.ResultSetImpl.first(ResultSetImpl.java:1164)
at me.confuser.banmanager.internal.hikari.pool.HikariProxyResultSet.first(HikariProxyResultSet.java)
at me.confuser.banmanager.internal.ormlite.jdbc.JdbcDatabaseResults.first(JdbcDatabaseResults.java:58)
at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNextThrow(SelectIterator.java:79)
at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNext(SelectIterator.java:98)
... 6 more
[11:18:16] [Craft Scheduler Thread - 6/WARN]: Exception in thread "Craft Scheduler Thread - 6"
[11:18:16] [Craft Scheduler Thread - 6/WARN]: org.apache.commons.lang.UnhandledException: Plugin BanManager v5.10.0-SNAPSHOT generated an exception while executing task 3162
at org.bukkit.craftbukkit.v1_8_R3.scheduler.CraftAsyncTask.run(CraftAsyncTask.java:56)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.IllegalStateException: Errors getting more results of class me.confuser.banmanager.data.PlayerWarnData
at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNext(SelectIterator.java:103)
at me.confuser.banmanager.listeners.JoinListener$1.run(JoinListener.java:236)
at org.bukkit.craftbukkit.v1_8_R3.scheduler.CraftTask.run(CraftTask.java:71)
at org.bukkit.craftbukkit.v1_8_R3.scheduler.CraftAsyncTask.run(CraftAsyncTask.java:53)
... 3 more
Caused by: java.sql.SQLException: Connection is closed
at me.confuser.banmanager.internal.hikari.pool.ProxyConnection$ClosedConnection$1.invoke(ProxyConnection.java:468)
at com.sun.proxy.$Proxy32.clearWarnings(Unknown Source)
at me.confuser.banmanager.internal.hikari.pool.ProxyConnection.close(ProxyConnection.java:241)
at me.confuser.banmanager.internal.ormlite.jdbc.JdbcDatabaseConnection.close(JdbcDatabaseConnection.java:139)
at me.confuser.banmanager.internal.ormlite.jdbc.DataSourceConnectionSource.releaseConnection(DataSourceConnectionSource.java:130)
at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.close(SelectIterator.java:247)
at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNextThrow(SelectIterator.java:84)
at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNext(SelectIterator.java:98)
... 6 more
Build 66 from v5.10.0-SNAPSHOT
Can also confirm, running 5.9.0
[02:12:27] [Craft Scheduler Thread - 1091/WARN]: Exception in thread "Craft Scheduler Thread - 1091" [02:12:27] [Craft Scheduler Thread - 1091/WARN]: org.apache.commons.lang.UnhandledException: Plugin BanManager v5.9.0 generated an exception while executing task 25723 at org.bukkit.craftbukkit.v1_9_R2.scheduler.CraftAsyncTask.run(CraftAsyncTask.java:56) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: java.lang.IllegalStateException: Errors getting more results of class me.confuser.banmanager.data.PlayerNoteData at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNext(SelectIterator.java:103) at me.confuser.banmanager.listeners.JoinListener$1.run(JoinListener.java:204) at org.bukkit.craftbukkit.v1_9_R2.scheduler.CraftTask.run(CraftTask.java:71) at org.bukkit.craftbukkit.v1_9_R2.scheduler.CraftAsyncTask.run(CraftAsyncTask.java:53) ... 3 more Caused by: java.sql.SQLException: Operation not allowed after ResultSet closed at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:959) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:898) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:887) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:862) at com.mysql.jdbc.ResultSetImpl.checkClosed(ResultSetImpl.java:743) at com.mysql.jdbc.ResultSetImpl.next(ResultSetImpl.java:6320) at me.confuser.banmanager.internal.hikari.pool.HikariProxyResultSet.next(HikariProxyResultSet.java) at me.confuser.banmanager.internal.ormlite.jdbc.JdbcDatabaseResults.next(JdbcDatabaseResults.java:64) at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNextThrow(SelectIterator.java:81) at me.confuser.banmanager.internal.ormlite.stmt.SelectIterator.hasNext(SelectIterator.java:98) ... 6 more
No, debug within BanManager/config.yml
On Mon, Jun 6, 2016 at 2:18 PM, Very Evil Olaf [email protected]
wrote:
Debug mode from Spigot itself?
—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
#493 (comment),
or mute the thread
https://github.com/notifications/unsubscribe/ABlQdf5JaZL51KwO1l2-CeJg11A5f-c3ks5qJB4QgaJpZM4G__0r
.
Is anyone able to run this with debug mode enabled? Hoping to catch the full output along with this error to see what is going on. Be warned, it'll be very noisy and probably use up a considerable amount of space within your log file.
@confuser Restarted with debug-mode activated. Banmanager spam exceptions quite often but they seem to happen completely at random. Will post log next time I see it happen.
Brilliant, thanks @Foorack
@Foorack did this problem occur again with debug enabled?