search

Civcraft / RealisticBiomes

Do not open issues here; open them on the maintained fork @ DevotedMC
https://github.com/DevotedMC/RealisticBiomes
7 stars 14 forks source link

Database stack on shutdown #71

Open ttk2 opened 8 years ago

ttk2 commented 8 years ago

Seeing this on every shutdown of any server on the current civtemp setup, no other RB stacks during operation.

The last packet successfully received from the server was 1,054,999 milliseconds ago. The last packet sent successfully to the server was 0 milliseconds ago. 2016-02-12 17:01:32 [ERROR] [RealisticBiomes] error in run() when shutting down! com.avaje.ebeaninternal.server.lib.sql.DataSourceException: unable to set autocommit to false in saveAllAndStop at com.untamedears.realisticbiomes.persist.PlantManager$3.run(PlantManager.java:368) [RealisticBiomes-1.0.4.jar:?] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_66-internal] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_66-internal] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_66-internal] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_66-internal] at java.lang.Thread.run(Thread.java:745) [?:1.8.0_66-internal] Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 1,054,999 milliseconds ago. The last packet sent successfully to the server was 0 milliseconds ago. at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:1.8.0_66-internal] at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[?:1.8.0_66-internal] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[?:1.8.0_66-internal] at java.lang.reflect.Constructor.newInstance(Constructor.java:422) ~[?:1.8.0_66-internal] at com.mysql.jdbc.Util.handleNewInstance(Util.java:407) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1116) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3082) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2968) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3516) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1986) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2140) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2620) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:5022) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.untamedears.realisticbiomes.persist.PlantManager$3.run(PlantManager.java:365) ~[?:?] ... 5 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:2529) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2979) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2968) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3516) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1986) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2140) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2620) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.mysql.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:5022) ~[spigot.jar:git-Spigot-db6de12-880a532] at com.untamedears.realisticbiomes.persist.PlantManager$3.run(PlantManager.java:365) ~[?:?] ... 5 more

Arebs commented 8 years ago

Hey there, I looked over the problem and got a question: Why is ExecutorService used here to write in the DB at the end? As far as I know, JDCB doesn't support asynchronous calls. If you want, I can debug this later (in about 8-9 hours) and fix the Problem

ProgrammerDan commented 8 years ago

It's a timeout problem. When a server isn't in active use, it holds the connection open past MariaDB/MySQL's configured timeout, and on next-write the connection fails. Up until the write, however, the connection self-reports as being alive and well.

One fix for this is simple, just run an asynchronous process that sends a keepalive query to MySQL (something like "SELECT 1;") every minute or two. The other fix would be to use an actual connection pool, which would handle these kinds of problems for us.

@Arebs If I recall, the asynchronous bit is simply a thread is spawned to handle the dump to the database so that the rest of the shutdown process can continue without being delayed by the cache dump to RealisticBiome's database. As for JDBC itself, it's not an asynchronous call, per sey; all the calls against the driver are well-ordered and "synchronous" from its point of view, however, the thread that utilizes JDBC can absolutely be "asynchronous" from the main application's point of view.

Arebs commented 8 years ago

@ProgrammerDan ahh, now I understand, thanks. The first Solution may sound simple, but this will not work if the Connection get lost or terminated. The Connection Pool sounds like a good solution, either in a singleton for the complete Plugin or simple in the Class

ProgrammerDan commented 8 years ago

So, I'd recommend the first version for now. Longer term switching to a connection pool is planned, but would ideally need to be applied consistently across all the plugins leveraging database.

In that case it'd probably be worthwhile rolling the pooling up into CivModCore and enforcing that each plugin extend from there.

erocs commented 8 years ago

That was the plan. I think there was even an open issue to move DB handling to CivModCore so a connection pool could be used.

On Wed, Feb 17, 2016 at 9:14 AM, Daniel Boston notifications@github.com wrote:

So, I'd recommend the first version for now. Longer term switching to a connection pool is planned, but would ideally need to be applied consistently across all the plugins leveraging database.

In that case it'd probably be worthwhile rolling the pooling up into CivModCore and enforcing that each plugin extend from there.

— Reply to this email directly or view it on GitHub https://github.com/Civcraft/RealisticBiomes/issues/71#issuecomment-185306843 .