MyEssentials / MyTown2

Version 2 of MyTown - A Minecraft Server Protection Mod
The Unlicense
35 stars 22 forks source link

Problem with JDBC connection after server was not active #509

Open kratz74 opened 7 years ago

kratz74 commented 7 years ago

Looks like JDBC connection handling may require some rewrite. I was trying to register new town after some time of no activity on the server and it failed with following exception:

[12:01:08] [Server thread/ERROR] [MyTown2]: Failed to save Town Spawn!
[12:01:08] [Server thread/ERROR] [MyTown2]: java.sql.SQLException: Could not retrieve transation read-only status server
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1094)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:997)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:983)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:928)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:959)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:949)
        at com.mysql.jdbc.ConnectionImpl.isReadOnly(ConnectionImpl.java:3967)
        at com.mysql.jdbc.ConnectionImpl.isReadOnly(ConnectionImpl.java:3938)
        at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2295)
        at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2262)
        at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2246)
        at mytown.new_datasource.MyTownDatasource.saveTown(MyTownDatasource.java:582)
        at mytown.new_datasource.MyTownUniverse.configureTown(MyTownUniverse.java:86)
        at mytown.new_datasource.MyTownUniverse.newTown(MyTownUniverse.java:51)
        at mytown.commands.CommandsOutsider.newTownCommand(CommandsOutsider.java:152)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:497)
        at mypermissions.command.core.entities.CommandTreeNode.commandCall(CommandTreeNode.java:100)
        at mypermissions.command.core.entities.CommandTree.commandCall(CommandTree.java:40)
        at mypermissions.command.core.entities.CommandModel.func_71515_b(CommandModel.java:46)
        at net.minecraft.command.CommandHandler.func_71556_a(CommandHandler.java:94)
        at net.minecraft.network.NetHandlerPlayServer.func_147361_d(NetHandlerPlayServer.java:739)
        at net.minecraft.network.NetHandlerPlayServer.func_147354_a(NetHandlerPlayServer.java:718)
        at net.minecraft.network.play.client.C01PacketChatMessage.func_148833_a(SourceFile:37)
        at net.minecraft.network.play.client.C01PacketChatMessage.func_148833_a(SourceFile:9)
        at net.minecraft.network.NetworkManager.func_74428_b(NetworkManager.java:212)
        at net.minecraft.network.NetworkSystem.func_151269_c(NetworkSystem.java:165)
        at net.minecraft.server.MinecraftServer.func_71190_q(MinecraftServer.java:659)
        at net.minecraft.server.dedicated.DedicatedServer.func_71190_q(DedicatedServer.java:334)
        at net.minecraft.server.MinecraftServer.func_71217_p(MinecraftServer.java:547)
        at fastcraft.at.a(F:978)
        at fastcraft.H.aq(F:36)
        at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:396)
        at net.minecraft.server.MinecraftServer$2.run(MinecraftServer.java:685)
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 31,174,760 milliseconds ago.  The last packet sent successfully to the server was 29 milliseconds ago.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:422)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:408)
        at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1137)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3697)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3586)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4131)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2597)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2758)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2820)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2769)
        at com.mysql.jdbc.StatementImpl.executeQuery(StatementImpl.java:1569)
        at com.mysql.jdbc.ConnectionImpl.isReadOnly(ConnectionImpl.java:3961)
        ... 29 more
Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
        at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3143)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3597)
        ... 37 more

Next attempt passed so looks like database connection was renewed. screen shot 2016-09-16 at 12 08 22

Think you shall add some reconnect attempt into SQLException catch block or add connection checking code similar to whatI'm doing in my own mod, see https://github.com/kratz74/KratzAuth/blob/master/src/mc/server/DatabaseLookup.java method String getPasswordHash(String) and void checkConnection() which will just silently renew dead JDBC connection before doing anything else. Another thing to do is to use JDBC connection pooling, but this will consume more system resources and it makes sense only under heavy load.