Server wont stop with MH installed if rewards form unloaded world

Question

Server wont stop with MH installed if rewards form unloaded world

FabioZumbi12 opened this issue 4 years ago · 17 comments

FabioZumbi12 commented 4 years ago

Using the release 7.5.0 it wont let the server to stop but now sometimes with the error, and sometimes no, but always not allows to server stops.

What i've tested: With plugin installed, just started server, wait to load and then stopped, it freezes on saving worlds... infinitely... tried this a lot of times and same result (on my production server, there's a plugin to auto restart, and was frozen from 4:00 to 8:30 until i killed the process and started again).

Removed the plugin from server, started server, wait to load and then stopped, unloaded and stopped correctly! Made this a lot of times too.

Server running on Windows10
MoHunting: 7.5.0 (at the moment, the same as the last dev build)
Paper: 1.16.1 build 40
Java 1.8

May be not related (or yes), but if the rewards.yml have some rewards from an unloaded world, i have this errors spammed on server start for every reward on rewards file:

[13:19:32] [Server thread/INFO]: [MobHunting] Enabling MobHunting v7.5.0
[13:19:32] [Server thread/INFO]: [MobHunting] Your config version is 1
[13:19:32] [Server thread/INFO]: [MobHunting] Existing config.yml loaded.
[13:19:32] [Server thread/INFO]: [MobHunting] Config.yml was backed up to plugins\MobHunting\backup\config.yml.bak461
[13:19:33] [Server thread/INFO]: [BagOfGoldCore] BagOfGold is not installed on this server
[13:19:33] [Server thread/INFO]: [BagOfGoldCore] Enabling compatibility with MobHunting (7.5.0)
[13:19:33] [Server thread/ERROR]: [org.bukkit.configuration.serialization.ConfigurationSerialization] Could not call method 'public static org.bukkit.Location org.bukkit.Location.deserialize(java.util.Map)' of class org.bukkit.Location for deserialization
java.lang.IllegalArgumentException: unknown world
	at org.bukkit.Location.deserialize(Location.java:1123) ~[patched_1.16.1.jar:git-Paper-39]
	at sun.reflect.GeneratedMethodAccessor29.invoke(Unknown Source) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_221]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_221]
	at org.bukkit.configuration.serialization.ConfigurationSerialization.deserializeViaMethod(ConfigurationSerialization.java:85) ~[patched_1.16.1.jar:git-Paper-39]
	at org.bukkit.configuration.serialization.ConfigurationSerialization.deserialize(ConfigurationSerialization.java:127) ~[patched_1.16.1.jar:git-Paper-39]
	at org.bukkit.configuration.serialization.ConfigurationSerialization.deserializeObject(ConfigurationSerialization.java:207) ~[patched_1.16.1.jar:git-Paper-39]
	at org.bukkit.configuration.file.YamlConstructor$ConstructCustomObject.construct(YamlConstructor.java:37) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObjectNoCheck(BaseConstructor.java:230) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObject(BaseConstructor.java:219) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructMapping2ndStep(BaseConstructor.java:479) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.SafeConstructor.constructMapping2ndStep(SafeConstructor.java:190) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructMapping(BaseConstructor.java:460) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.SafeConstructor$ConstructYamlMap.construct(SafeConstructor.java:556) ~[patched_1.16.1.jar:git-Paper-39]
	at org.bukkit.configuration.file.YamlConstructor$ConstructCustomObject.construct(YamlConstructor.java:28) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObjectNoCheck(BaseConstructor.java:230) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObject(BaseConstructor.java:219) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructMapping2ndStep(BaseConstructor.java:479) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.SafeConstructor.constructMapping2ndStep(SafeConstructor.java:190) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructMapping(BaseConstructor.java:460) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.SafeConstructor$ConstructYamlMap.construct(SafeConstructor.java:556) ~[patched_1.16.1.jar:git-Paper-39]
	at org.bukkit.configuration.file.YamlConstructor$ConstructCustomObject.construct(YamlConstructor.java:28) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObjectNoCheck(BaseConstructor.java:230) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructObject(BaseConstructor.java:219) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.BaseConstructor.constructDocument(BaseConstructor.java:173) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.constructor.BaseConstructor.getSingleData(BaseConstructor.java:157) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.Yaml.loadFromReader(Yaml.java:472) ~[patched_1.16.1.jar:git-Paper-39]
	at org.yaml.snakeyaml.Yaml.load(Yaml.java:398) ~[patched_1.16.1.jar:git-Paper-39]
	at org.bukkit.configuration.file.YamlConfiguration.loadFromString(YamlConfiguration.java:57) ~[patched_1.16.1.jar:git-Paper-39]
	at org.bukkit.configuration.file.FileConfiguration.load(FileConfiguration.java:160) ~[patched_1.16.1.jar:git-Paper-39]
	at org.bukkit.configuration.file.FileConfiguration.load(FileConfiguration.java:128) ~[patched_1.16.1.jar:git-Paper-39]
	at one.lindegaard.Core.rewards.RewardBlockManager.migrateRewardsFromMobHunting(RewardBlockManager.java:177) ~[?:?]
	at one.lindegaard.Core.rewards.RewardBlockManager.load(RewardBlockManager.java:165) ~[?:?]
	at one.lindegaard.Core.rewards.RewardBlockManager.<init>(RewardBlockManager.java:39) ~[?:?]
	at one.lindegaard.Core.Core.<init>(Core.java:55) ~[?:?]
	at one.lindegaard.MobHunting.MobHunting.onEnable(MobHunting.java:143) ~[?:?]
	at org.bukkit.plugin.java.JavaPlugin.setEnabled(JavaPlugin.java:263) ~[patched_1.16.1.jar:git-Paper-39]
	at org.bukkit.plugin.java.JavaPluginLoader.enablePlugin(JavaPluginLoader.java:380) ~[patched_1.16.1.jar:git-Paper-39]
	at org.bukkit.plugin.SimplePluginManager.enablePlugin(SimplePluginManager.java:483) ~[patched_1.16.1.jar:git-Paper-39]
	at org.bukkit.craftbukkit.v1_16_R1.CraftServer.enablePlugin(CraftServer.java:500) ~[patched_1.16.1.jar:git-Paper-39]
	at org.bukkit.craftbukkit.v1_16_R1.CraftServer.enablePlugins(CraftServer.java:414) ~[patched_1.16.1.jar:git-Paper-39]
	at net.minecraft.server.v1_16_R1.MinecraftServer.loadWorld(MinecraftServer.java:471) ~[patched_1.16.1.jar:git-Paper-39]
	at net.minecraft.server.v1_16_R1.DedicatedServer.init(DedicatedServer.java:241) ~[patched_1.16.1.jar:git-Paper-39]
	at net.minecraft.server.v1_16_R1.MinecraftServer.v(MinecraftServer.java:940) ~[patched_1.16.1.jar:git-Paper-39]
	at net.minecraft.server.v1_16_R1.MinecraftServer.lambda$a$0(MinecraftServer.java:177) ~[patched_1.16.1.jar:git-Paper-39]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_221]

My rewards file to you try to reproduce: rewards.zip

Rocologo commented 4 years ago

How goes?

Rocologo · Answer 1 · 2020-07-02T18:08:20.000Z

yes, but i want to find the bug. you are not the only one who delete a world.

Rocologo · Answer 2 · 2020-07-02T17:20:56.000Z

Please do report more than one bug per ticket. I will see if i can add a check to see if the world is deleted.

FabioZumbi12 · Answer 3 · 2020-07-02T17:39:06.000Z

Its because i have tested after some time and got the cause its this errors on start plugin, causing to do not let stop the server. I've removed the rewards file and started without errors, and stopped the server with success!!

FabioZumbi12 · Answer 4 · 2020-07-03T06:45:53.000Z

Its seems the problem of server don't stop is not caused only by that errors when unloaded worlds:

[03:31:32 INFO]: [MobHunting] Disabling MobHunting v7.5.0
[03:32:21 INFO]: UUID of player Sixie is d77e6e33-306a-38a1-ae44-6da43c8b77d6
[03:32:39 INFO]: UUID of player Sixie is d77e6e33-306a-38a1-ae44-6da43c8b77d6
[03:32:53 INFO]: UUID of player Sixie is d77e6e33-306a-38a1-ae44-6da43c8b77d6
[03:33:16 INFO]: UUID of player LegendsOfSona is c4cdb735-efb9-3d46-8be1-550dc58e4ffd
[03:33:41 INFO]: UUID of player Sixie is d77e6e33-306a-38a1-ae44-6da43c8b77d6
[03:34:01 INFO]: UUID of player LegendsOfSona is c4cdb735-efb9-3d46-8be1-550dc58e4ffd
[03:34:09 INFO]: UUID of player Suforever is e9daed10-7d89-39e9-aa9a-5d0d8119e29b
[03:34:42 INFO]: UUID of player LegendsOfSona is c4cdb735-efb9-3d46-8be1-550dc58e4ffd
[03:34:47 INFO]: UUID of player Sixie is d77e6e33-306a-38a1-ae44-6da43c8b77d6
[03:35:00 INFO]: UUID of player LegendsOfSona is c4cdb735-efb9-3d46-8be1-550dc58e4ffd
[03:35:24 WARN]: one.lindegaard.Core.storage.DataStoreException: org.sqlite.SQLiteException: [SQLITE_BUSY]  The database file is locked (database is locked)
[03:35:24 WARN]: 	at one.lindegaard.Core.storage.DatabaseDataStore.savePlayerSettings(DatabaseDataStore.java:247)
[03:35:24 WARN]: 	at one.lindegaard.Core.storage.async.StoreTask.run(StoreTask.java:29)
[03:35:24 WARN]: 	at one.lindegaard.Core.storage.async.StoreTask.run(StoreTask.java:10)
[03:35:24 WARN]: 	at one.lindegaard.Core.storage.DataStoreManager$TaskThread.run(DataStoreManager.java:313)
[03:35:24 WARN]: Caused by: org.sqlite.SQLiteException: [SQLITE_BUSY]  The database file is locked (database is locked)
[03:35:24 WARN]: 	at org.sqlite.core.DB.newSQLException(DB.java:1010)
[03:35:24 WARN]: 	at org.sqlite.core.DB.newSQLException(DB.java:1022)
[03:35:24 WARN]: 	at org.sqlite.core.DB.throwex(DB.java:987)
[03:35:24 WARN]: 	at org.sqlite.core.DB.exec(DB.java:185)
[03:35:24 WARN]: 	at org.sqlite.SQLiteConnection.commit(SQLiteConnection.java:404)
[03:35:24 WARN]: 	at one.lindegaard.Core.storage.DatabaseDataStore.savePlayerSettings(DatabaseDataStore.java:232)
[03:35:24 WARN]: 	... 3 more
[03:35:52 INFO]: UUID of player Sixie is d77e6e33-306a-38a1-ae44-6da43c8b77d6
[03:35:53 INFO]: UUID of player LegendsOfSona is c4cdb735-efb9-3d46-8be1-550dc58e4ffd
[03:36:28 INFO]: [Votifier] [Votifier] Diference: 442687
[03:40:13 INFO]: UUID of player LegendsOfSona is c4cdb735-efb9-3d46-8be1-550dc58e4ffd
[03:40:33 INFO]: UUID of player LegendsOfSona is c4cdb735-efb9-3d46-8be1-550dc58e4ffd

Rocologo · Answer 5 · 2020-07-03T09:17:09.000Z

I would like to see your full server.log on start and stop (were you get this error) and please enable debug mode "/mh debug so I hopefully can see what happens. The SQL database might end up locked if you have any other error, and it is this "any other error" which might be the root cause.

Rocologo · Answer 6 · 2020-07-03T14:55:43.000Z

Okay this gives me something to look for and it can definitely cause the server to hang on stop.

Rocologo · Answer 7 · 2020-07-03T15:07:22.000Z

You should have a debug line before this bug. Starting with "RandomBounty to be inserted". Do you have this line? what does the last part say?

FabioZumbi12 · Answer 8 · 2020-07-03T12:15:17.000Z

After that log i have removed MH to do not freeze my server until i sleep and the server auto-restart. But before that log, the server have run from 20h to 3:30h making impossible to upload all logs for you, but searching for errors in this period i got this one (no cut, no other server start errors):

[21:09:04] [MH TaskThread/WARN]: Exception in thread "MH TaskThread" java.lang.NullPointerException
[21:09:04] [MH TaskThread/WARN]: 	at one.lindegaard.Core.storage.DatabaseDataStore.getPlayerId(DatabaseDataStore.java:375)
[21:09:04] [MH TaskThread/WARN]: 	at one.lindegaard.Core.storage.DataStoreManager.getPlayerId(DataStoreManager.java:97)
[21:09:04] [MH TaskThread/WARN]: 	at one.lindegaard.MobHunting.storage.SQLiteDataStore.saveBounties(SQLiteDataStore.java:294)
[21:09:04] [MH TaskThread/WARN]: 	at one.lindegaard.MobHunting.storage.asynch.StoreTask.run(StoreTask.java:45)
[21:09:04] [MH TaskThread/WARN]: 	at one.lindegaard.MobHunting.storage.asynch.StoreTask.run(StoreTask.java:12)
[21:09:04] [MH TaskThread/WARN]: 	at one.lindegaard.MobHunting.storage.DataStoreManager$TaskThread.run(DataStoreManager.java:334)

And then on 3:35 that one mentioned before!

FabioZumbi12 · Answer 9 · 2020-07-03T19:08:11.000Z

I'll install your new build and look until 20h (now is 16h here on Brazil)

FabioZumbi12 · Answer 10 · 2020-07-04T03:08:31.000Z

I've sent you a log from 20h to 23:59h with debug enabled and the b1057. Sent to you via Spigot forum because the info exposed on log.

FabioZumbi12 · Answer 11 · 2020-07-16T12:41:36.000Z

Hi,

Installed on my server now at 9:40 (pt-br), the next reboot its at 16h and ill see if stops and look for more errors ;)

Rocologo · Answer 12 · 2020-07-16T12:42:26.000Z

Thank you :-)

Rocologo · Answer 13 · 2020-07-16T10:47:02.000Z

@FabioZumbi12 Thank you for the log I think I know whats wrong. You have an SQL error in the log 21:12 which can cause the server to hang, when it try to close the database. The bug was related to the Random Bounties

Its hard for me to test because I dont see the problem on my test servers, but I think I know what the error is and I have tried to make a fix for this problem.

Could you please help me with the testing?

Rocologo · Answer 14 · 2020-07-16T10:47:22.000Z

Try build latest build

https://fractal.lindegaard.one:8181/job/MobHunting/lastSuccessfulBuild/

Rocologo · Answer 15 · 2020-07-16T11:03:36.000Z

PS I noticed that Integration to StackMob was disabeled. In latest build I re-added support for StackMob. The DEV had changed his API. Integration to MCMMO should world as well

FabioZumbi12 · Answer 16 · 2020-07-18T21:14:43.000Z

Sorry, i am little busy, but its seems is solved. No more errors related to sql and the sever stops correctly. I just cant know if the unloaded issue is solved because i have reset the rewards files.

Share to