ReportRTS breaks occasionally about reportrts HOT 18 CLOSED

There definitely is a bug somewhere causing the database to lock, I have experienced this myself a few times when using SQLite lately. I am however not sure how it happens, or exactly where it happens.

If you use MySQL, this will not occur.

from reportrts.

Just question: Will the /reportrts stats command still work with MySQL?

Thanks!

from reportrts.

That it should, let me know if it doesn't and I'll take a look.

from reportrts.

I am using MySQL and it appears to lock as well. Also, next time close a 4 month old bug.

from reportrts.

MySQL is incapable of locking. I have been using it for about a year now. MySQL has never once had an issue.

from reportrts.

Weird, I've had to reload this plugin a few times in the past week. I'll see if there are any logs I can pull out.

from reportrts.

This is how it bugs out.

2013-02-14 20:15:43 [INFO] CH: Running original command on player krisdestruction ----> /ticket test
2013-02-14 20:15:43 [INFO] krisdestruction issued server command: /modreq test
2013-02-14 20:15:43 [SEVERE] com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.Connection was implicitly closed by the driver.
2013-02-14 20:15:43 [SEVERE] at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
2013-02-14 20:15:43 [SEVERE] at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
2013-02-14 20:15:43 [SEVERE] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
2013-02-14 20:15:43 [SEVERE] at java.lang.reflect.Constructor.newInstance(Constructor.java:525)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.Util.handleNewInstance(Util.java:407)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.Util.getInstance(Util.java:382)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1013)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:982)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:927)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1213)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1200)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.ConnectionImpl.prepareStatement(ConnectionImpl.java:4203)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.ConnectionImpl.prepareStatement(ConnectionImpl.java:4169)
2013-02-14 20:15:43 [SEVERE] at com.nyancraft.reportrts.persistence.SQLDB.getUserId(SQLDB.java:78)
2013-02-14 20:15:43 [SEVERE] at com.nyancraft.reportrts.command.ModreqCommand.onCommand(ModreqCommand.java:54)
2013-02-14 20:15:43 [SEVERE] at org.bukkit.command.PluginCommand.execute(PluginCommand.java:44)
2013-02-14 20:15:43 [SEVERE] at org.bukkit.command.SimpleCommandMap.dispatch(SimpleCommandMap.java:186)
2013-02-14 20:15:43 [SEVERE] at org.bukkit.craftbukkit.v1_4_R1.CraftServer.dispatchCommand(CraftServer.java:514)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.PlayerConnection.handleCommand(PlayerConnection.java:980)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.PlayerConnection.chat(PlayerConnection.java:898)
2013-02-14 20:15:43 [SEVERE] at org.bukkit.craftbukkit.v1_4_R1.entity.CraftPlayer.chat(CraftPlayer.java:234)
2013-02-14 20:15:43 [SEVERE] at com.laytonsmith.abstraction.bukkit.BukkitMCPlayer.chat(BukkitMCPlayer.java:53)
2013-02-14 20:15:43 [SEVERE] at com.laytonsmith.core.AliasCore$1.done(AliasCore.java:119)
2013-02-14 20:15:43 [SEVERE] at com.laytonsmith.core.MScriptCompiler.execute(MScriptCompiler.java:527)
2013-02-14 20:15:43 [SEVERE] at com.laytonsmith.core.Script.run(Script.java:179)
2013-02-14 20:15:43 [SEVERE] at com.laytonsmith.core.AliasCore.alias(AliasCore.java:104)
2013-02-14 20:15:43 [SEVERE] at com.laytonsmith.commandhelper.CommandHelperListener.runAlias(CommandHelperListener.java:79)
2013-02-14 20:15:43 [SEVERE] at com.laytonsmith.commandhelper.CommandHelperListener.onPlayerCommandPreprocess(CommandHelperListener.java:119)
2013-02-14 20:15:43 [SEVERE] at sun.reflect.GeneratedMethodAccessor238.invoke(Unknown Source)
2013-02-14 20:15:43 [SEVERE] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2013-02-14 20:15:43 [SEVERE] at java.lang.reflect.Method.invoke(Method.java:601)
2013-02-14 20:15:43 [SEVERE] at org.bukkit.plugin.java.JavaPluginLoader$1.execute(JavaPluginLoader.java:425)
2013-02-14 20:15:43 [SEVERE] at org.bukkit.plugin.RegisteredListener.callEvent(RegisteredListener.java:62)
2013-02-14 20:15:43 [SEVERE] at org.bukkit.plugin.TimedRegisteredListener.callEvent(TimedRegisteredListener.java:35)
2013-02-14 20:15:43 [SEVERE] at org.bukkit.plugin.SimplePluginManager.fireEvent(SimplePluginManager.java:477)
2013-02-14 20:15:43 [SEVERE] at org.bukkit.plugin.SimplePluginManager.callEvent(SimplePluginManager.java:462)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.PlayerConnection.handleCommand(PlayerConnection.java:972)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.PlayerConnection.chat(PlayerConnection.java:898)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.PlayerConnection.a(PlayerConnection.java:853)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.Packet3Chat.handle(Packet3Chat.java:44)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.NetworkManager.b(NetworkManager.java:290)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.PlayerConnection.d(PlayerConnection.java:113)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.ServerConnection.b(SourceFile:39)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.DedicatedServerConnection.b(SourceFile:30)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.MinecraftServer.r(MinecraftServer.java:598)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.DedicatedServer.r(DedicatedServer.java:224)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.MinecraftServer.q(MinecraftServer.java:494)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.MinecraftServer.run(MinecraftServer.java:427)
2013-02-14 20:15:43 [SEVERE] at net.minecraft.server.v1_4_R1.ThreadServerApplication.run(SourceFile:849)
2013-02-14 20:15:43 [SEVERE] Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 48,403,913 milliseconds ago. The last packet sent successfully to the server was 48,403,913 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
2013-02-14 20:15:43 [SEVERE] at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
2013-02-14 20:15:43 [SEVERE] at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
2013-02-14 20:15:43 [SEVERE] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
2013-02-14 20:15:43 [SEVERE] at java.lang.reflect.Constructor.newInstance(Constructor.java:525)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.Util.handleNewInstance(Util.java:407)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1116)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3348)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1967)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2140)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2626)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2111)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2273)
2013-02-14 20:15:43 [SEVERE] at com.nyancraft.reportrts.persistence.SQLDB.getUserId(SQLDB.java:80)
2013-02-14 20:15:43 [SEVERE] ... 35 more
2013-02-14 20:15:43 [SEVERE] Caused by: java.net.SocketException: Broken pipe
2013-02-14 20:15:43 [SEVERE] at java.net.SocketOutputStream.socketWrite0(Native Method)
2013-02-14 20:15:43 [SEVERE] at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109)
2013-02-14 20:15:43 [SEVERE] at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
2013-02-14 20:15:43 [SEVERE] at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
2013-02-14 20:15:43 [SEVERE] at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
2013-02-14 20:15:43 [SEVERE] at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3329)
2013-02-14 20:15:43 [SEVERE] ... 41 more

This is how I reloaded it.

2013-02-14 20:15:57 [INFO] [ReportRTS] Disabling ReportRTS v1.0.0-b110
2013-02-14 20:15:57 [INFO] [PluginReloader] krisdestruction has unloaded ReportRTS.
2013-02-14 20:15:57 [INFO] [ReportRTS] Enabling ReportRTS v1.0.0-b110
2013-02-14 20:15:57 [INFO] [ReportRTS] Connecting to MySQL.
2013-02-14 20:15:57 [INFO] [ReportRTS] Successfully connected and checked tables, will use MySQL.
2013-02-14 20:15:57 [INFO] [ReportRTS] Vault and a compatible permissions manager was found. Using Vault for permissions.
2013-02-14 20:15:57 [INFO] [PluginReloader] krisdestruction has loaded ReportRTS.
2013-02-14 20:15:57 [INFO] [PluginReloader] krisdestruction reloaded ReportRTS.

Tell me if you need anything else!

from reportrts.

More logs!

2013-02-12 18:01:59 [INFO] CH: Running original command on player zadiamondmasta ----> /ticket my fence was stolen and my friends house is completly gone
2013-02-12 18:01:59 [INFO] zadiamondmasta issued server command: /modreq my fence was stolen and my friends house is completly gone
2013-02-12 18:01:59 [SEVERE] com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 29,402,223 milliseconds ago. The last packet sent successfully to the server was 0 milliseconds ago.
2013-02-12 18:01:59 [SEVERE] at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
2013-02-12 18:01:59 [SEVERE] at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
2013-02-12 18:01:59 [SEVERE] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
2013-02-12 18:01:59 [SEVERE] at java.lang.reflect.Constructor.newInstance(Constructor.java:525)
2013-02-12 18:01:59 [SEVERE] at com.mysql.jdbc.Util.handleNewInstance(Util.java:407)
2013-02-12 18:01:59 [SEVERE] at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1116)
2013-02-12 18:01:59 [SEVERE] at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3082)
2013-02-12 18:01:59 [SEVERE] at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2968)
2013-02-12 18:01:59 [SEVERE] at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3516)
2013-02-12 18:01:59 [SEVERE] at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1986)
2013-02-12 18:01:59 [SEVERE] at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2140)
2013-02-12 18:01:59 [SEVERE] at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2626)
2013-02-12 18:01:59 [SEVERE] at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2111)
2013-02-12 18:01:59 [SEVERE] at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2273)
2013-02-12 18:01:59 [SEVERE] at com.nyancraft.reportrts.persistence.SQLDB.getUserId(SQLDB.java:80)
2013-02-12 18:01:59 [SEVERE] at com.nyancraft.reportrts.command.ModreqCommand.onCommand(ModreqCommand.java:54)
2013-02-12 18:01:59 [SEVERE] at org.bukkit.command.PluginCommand.execute(PluginCommand.java:44)
2013-02-12 18:01:59 [SEVERE] at org.bukkit.command.SimpleCommandMap.dispatch(SimpleCommandMap.java:186)
2013-02-12 18:01:59 [SEVERE] at org.bukkit.craftbukkit.v1_4_R1.CraftServer.dispatchCommand(CraftServer.java:514)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.PlayerConnection.handleCommand(PlayerConnection.java:980)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.PlayerConnection.chat(PlayerConnection.java:898)
2013-02-12 18:01:59 [SEVERE] at org.bukkit.craftbukkit.v1_4_R1.entity.CraftPlayer.chat(CraftPlayer.java:234)
2013-02-12 18:01:59 [SEVERE] at com.laytonsmith.abstraction.bukkit.BukkitMCPlayer.chat(BukkitMCPlayer.java:53)
2013-02-12 18:01:59 [SEVERE] at com.laytonsmith.core.AliasCore$1.done(AliasCore.java:119)
2013-02-12 18:01:59 [SEVERE] at com.laytonsmith.core.MScriptCompiler.execute(MScriptCompiler.java:527)
2013-02-12 18:01:59 [SEVERE] at com.laytonsmith.core.Script.run(Script.java:179)
2013-02-12 18:01:59 [SEVERE] at com.laytonsmith.core.AliasCore.alias(AliasCore.java:104)
2013-02-12 18:01:59 [SEVERE] at com.laytonsmith.commandhelper.CommandHelperListener.runAlias(CommandHelperListener.java:79)
2013-02-12 18:01:59 [SEVERE] at com.laytonsmith.commandhelper.CommandHelperListener.onPlayerCommandPreprocess(CommandHelperListener.java:119)
2013-02-12 18:01:59 [SEVERE] at sun.reflect.GeneratedMethodAccessor238.invoke(Unknown Source)
2013-02-12 18:01:59 [SEVERE] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2013-02-12 18:01:59 [SEVERE] at java.lang.reflect.Method.invoke(Method.java:601)
2013-02-12 18:01:59 [SEVERE] at org.bukkit.plugin.java.JavaPluginLoader$1.execute(JavaPluginLoader.java:425)
2013-02-12 18:01:59 [SEVERE] at org.bukkit.plugin.RegisteredListener.callEvent(RegisteredListener.java:62)
2013-02-12 18:01:59 [SEVERE] at org.bukkit.plugin.TimedRegisteredListener.callEvent(TimedRegisteredListener.java:35)
2013-02-12 18:01:59 [SEVERE] at org.bukkit.plugin.SimplePluginManager.fireEvent(SimplePluginManager.java:477)
2013-02-12 18:01:59 [SEVERE] at org.bukkit.plugin.SimplePluginManager.callEvent(SimplePluginManager.java:462)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.PlayerConnection.handleCommand(PlayerConnection.java:972)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.PlayerConnection.chat(PlayerConnection.java:898)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.PlayerConnection.a(PlayerConnection.java:853)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.Packet3Chat.handle(Packet3Chat.java:44)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.NetworkManager.b(NetworkManager.java:290)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.PlayerConnection.d(PlayerConnection.java:113)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.ServerConnection.b(SourceFile:39)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.DedicatedServerConnection.b(SourceFile:30)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.MinecraftServer.r(MinecraftServer.java:598)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.DedicatedServer.r(DedicatedServer.java:224)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.MinecraftServer.q(MinecraftServer.java:494)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.MinecraftServer.run(MinecraftServer.java:427)
2013-02-12 18:01:59 [SEVERE] at net.minecraft.server.v1_4_R1.ThreadServerApplication.run(SourceFile:849)
2013-02-12 18:01:59 [SEVERE] Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
2013-02-12 18:01:59 [SEVERE] at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2529)
2013-02-12 18:01:59 [SEVERE] at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2979)
2013-02-12 18:01:59 [SEVERE] ... 43 more

from reportrts.

Your MySQL server closed the connection, the plugin did nothing wrong.

from reportrts.

Why does it close it and if you don't know, why doesn't the plugin re-open the connection?

from reportrts.

I don't know why it closes, that is up to you to find out. The plugin is instructed to retry the connection as seen here. https://github.com/ProjectInfinity/ReportRTS/blob/master/src/main/java/lib/PatPeter/SQLibrary/MySQL.java#L85

It seems like the problem lies with you, is the MySQL server remote or local?

from reportrts.

Fair enough. Any tips on isolating the issue on my end?

MySQL is local on a dedi. Can you keep polling for a connection?

from reportrts.

I suggest watching the MySQL logs, and any other plugin that might be using MySQL. Do you run any other plugin than ReportRTS that utilizes SQLibrary?

from reportrts.

I don't know if any other plugin than ReportRTS utilizes the SQLibrary but I do know that other plugins use my MySQL connection perfectly without disconnecting or requiring a reload.

from reportrts.

Would this be the cause of the problem?
http://dev.bukkit.org/server-mods/sqlibrary/forum/help/48827-losing-mysql-connection/#p4

from reportrts.

I'm not sure if you considered this in your development plan, but I believe PatPeter the developer of SQLibrary is requiring that developers do not include the SQLibrary class files in the plugin but require that the JAR installed by end users. From the looks of it, BukkitDevs have started rejecting uploads that contain SQLibrary class files.

from reportrts.

I am aware of this. That is why I have decided to drop SQLibrary in favor of my own system that is going to work similarly as ReportRTS is already built around the system that is currently in place.

from reportrts.

PatPeter requiring users to install JAR manually
BukkitDev rejecting uploads with SQLibrary JAR
Such greedy developer (PatPeter)

from reportrts.