Occasionally loading fails

EvilOlaf commented 9 years ago

After running scavenger a couple of days it fails to load on startup with this error message:

[04:49:23] [Server thread/INFO]: [Scavenger] Enabling Scavenger v1.6-28
[04:49:23] [Server thread/INFO]: [Scavenger] Configuration loaded.
[04:49:23] [Server thread/INFO]: [Scavenger] Economy disabled. Item recovery will be free.
[04:49:23] [Server thread/ERROR]: Error occurred while enabling Scavenger v1.6-28 (Is it up to date?)
java.lang.RuntimeException: An internal error occured.
    at com.comphenix.protocol.reflect.accessors.DefaultMethodAccessor.invoke(DefaultMethodAccessor.java:20) ~[?:?]
    at com.comphenix.protocol.utility.StreamSerializer.deserializeItemStack(StreamSerializer.java:111) ~[?:?]
    at com.comphenix.protocol.utility.StreamSerializer.deserializeItemStack(StreamSerializer.java:236) ~[?:?]
    at com.cnaude.scavenger.RestorationManager.load(RestorationManager.java:121) ~[?:?]
    at com.cnaude.scavenger.RestorationManager.<init>(RestorationManager.java:36) ~[?:?]
    at com.cnaude.scavenger.Scavenger.onEnable(Scavenger.java:77) ~[?:?]
    at org.bukkit.plugin.java.JavaPlugin.setEnabled(JavaPlugin.java:321) ~[craftbukkit.jar:git-Spigot-c46583f-e6f9fd4]
    at org.bukkit.plugin.java.JavaPluginLoader.enablePlugin(JavaPluginLoader.java:335) [craftbukkit.jar:git-Spigot-c46583f-e6f9fd4]
    at org.bukkit.plugin.SimplePluginManager.enablePlugin(SimplePluginManager.java:405) [craftbukkit.jar:git-Spigot-c46583f-e6f9fd4]
    at org.bukkit.craftbukkit.v1_8_R1.CraftServer.loadPlugin(CraftServer.java:355) [craftbukkit.jar:git-Spigot-c46583f-e6f9fd4]
    at org.bukkit.craftbukkit.v1_8_R1.CraftServer.enablePlugins(CraftServer.java:315) [craftbukkit.jar:git-Spigot-c46583f-e6f9fd4]
    at net.minecraft.server.v1_8_R1.MinecraftServer.q(MinecraftServer.java:402) [craftbukkit.jar:git-Spigot-c46583f-e6f9fd4]
    at net.minecraft.server.v1_8_R1.MinecraftServer.k(MinecraftServer.java:370) [craftbukkit.jar:git-Spigot-c46583f-e6f9fd4]
    at net.minecraft.server.v1_8_R1.MinecraftServer.a(MinecraftServer.java:325) [craftbukkit.jar:git-Spigot-c46583f-e6f9fd4]
    at net.minecraft.server.v1_8_R1.DedicatedServer.init(DedicatedServer.java:211) [craftbukkit.jar:git-Spigot-c46583f-e6f9fd4]
    at net.minecraft.server.v1_8_R1.MinecraftServer.run(MinecraftServer.java:494) [craftbukkit.jar:git-Spigot-c46583f-e6f9fd4]
    at java.lang.Thread.run(Unknown Source) [?:1.7.0_71]
Caused by: java.io.IOException: Root tag must be a named compound tag
    at net.minecraft.server.v1_8_R1.NBTCompressedStreamTools.a(NBTCompressedStreamTools.java:62) ~[craftbukkit.jar:git-Spigot-c46583f-e6f9fd4]
    at net.minecraft.server.v1_8_R1.PacketDataSerializer.h(PacketDataSerializer.java:161) ~[craftbukkit.jar:git-Spigot-c46583f-e6f9fd4]
    at net.minecraft.server.v1_8_R1.PacketDataSerializer.i(PacketDataSerializer.java:196) ~[craftbukkit.jar:git-Spigot-c46583f-e6f9fd4]
    at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source) ~[?:?]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.7.0_71]
    at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.7.0_71]
    at com.comphenix.protocol.reflect.accessors.DefaultMethodAccessor.invoke(DefaultMethodAccessor.java:16) ~[?:?]
    ... 16 more

After deleting the .ser files in the Scavenger folder it works again. Running obliviously on Spigot 1.8 It did not seem that it had been already fixed in newer releases, but if so please let me know. Thanks.

Lunaphied commented 9 years ago

Obliviously? do you mean obviously? Looks like something is getting corrupted, can you upload the .ser files that cause this issue?

cnaude commented 9 years ago

This has been a random issue for a while now. I'd like to actually remove the ProtocolLib dependency completely. The serialization stuff doesnt seem to always work.

EvilOlaf commented 9 years ago

@modwizcode I admit I used a translator to find a maybe fitting definition for it. Guess I chose the wrong one :P As for now I helped myself by writing a small script which checks at startup if scavenger loading properly and if not it removes the .ser files and restarts again. I'll add something to "scavenge" these files before being dropped.

Lunaphied commented 9 years ago

Alright.

On Sat, Jan 31, 2015 at 12:14 AM, EvilOlaf notifications@github.com wrote:

@modwizcode https://github.com/modwizcode I admit I used an translator to find a maybe fitting definition for it. Guess I chose the wrong one :P As for now I helped myself by writing a small script which checks at startup if scavenger loading properly and if not it removes the .ser files and restarts again. I'll add something to "scavenge" these files before being dropped.

— Reply to this email directly or view it on GitHub https://github.com/cnaude/Scavenger/issues/10#issuecomment-72306566.

Starbuck Johnson, Java Developer www.modwiz.com | starbuck@modwiz.com

cnaude commented 9 years ago

I'm going to work on a fix for this.

cnaude commented 9 years ago

When you get a chance please try latest dev build: http://h.cnaude.org:8081/job/Scavenger/34/ It will still throw an error if there is a bad item but it should safely skip the item and go to the next. This should remove the need for automatic restarts.

EvilOlaf commented 9 years ago

Okey, I'll update tomorrow and then let's see what happens.

EvilOlaf commented 9 years ago

[04:06:02] [Server thread/ERROR]: Error occurred while enabling Scavenger v1.6-34 (Is it up to date?)
java.lang.RuntimeException: An internal error occured.
    at com.comphenix.protocol.reflect.accessors.DefaultMethodAccessor.invoke(DefaultMethodAccessor.java:20) ~[?:?]
    at com.comphenix.protocol.utility.StreamSerializer.deserializeItemStack(StreamSerializer.java:111) ~[?:?]
    at com.comphenix.protocol.utility.StreamSerializer.deserializeItemStack(StreamSerializer.java:236) ~[?:?]
    at com.cnaude.scavenger.RestorationManager.load(RestorationManager.java:118) ~[?:?]
    at com.cnaude.scavenger.RestorationManager.<init>(RestorationManager.java:33) ~[?:?]
    at com.cnaude.scavenger.Scavenger.onEnable(Scavenger.java:75) ~[?:?]
    at org.bukkit.plugin.java.JavaPlugin.setEnabled(JavaPlugin.java:321) ~[craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at org.bukkit.plugin.java.JavaPluginLoader.enablePlugin(JavaPluginLoader.java:335) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at org.bukkit.plugin.SimplePluginManager.enablePlugin(SimplePluginManager.java:405) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at org.bukkit.craftbukkit.v1_8_R1.CraftServer.loadPlugin(CraftServer.java:356) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at org.bukkit.craftbukkit.v1_8_R1.CraftServer.enablePlugins(CraftServer.java:316) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at net.minecraft.server.v1_8_R1.MinecraftServer.q(MinecraftServer.java:402) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at net.minecraft.server.v1_8_R1.MinecraftServer.k(MinecraftServer.java:370) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at net.minecraft.server.v1_8_R1.MinecraftServer.a(MinecraftServer.java:325) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at net.minecraft.server.v1_8_R1.DedicatedServer.init(DedicatedServer.java:211) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at net.minecraft.server.v1_8_R1.MinecraftServer.run(MinecraftServer.java:494) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at java.lang.Thread.run(Unknown Source) [?:1.7.0_71]
Caused by: java.io.IOException: Root tag must be a named compound tag
    at net.minecraft.server.v1_8_R1.NBTCompressedStreamTools.a(NBTCompressedStreamTools.java:62) ~[craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at net.minecraft.server.v1_8_R1.PacketDataSerializer.h(PacketDataSerializer.java:161) ~[craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at net.minecraft.server.v1_8_R1.PacketDataSerializer.i(PacketDataSerializer.java:196) ~[craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.7.0_71]
    at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[?:1.7.0_71]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.7.0_71]
    at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.7.0_71]
    at com.comphenix.protocol.reflect.accessors.DefaultMethodAccessor.invoke(DefaultMethodAccessor.java:16) ~[?:?]
    ... 16 more

Here are the the files: http://www.xup.in/dl,99867693/ignores.ser/ http://www.xup.in/dl,52437774/inv1.ser/

After deleting those it loaded fine again.

cnaude commented 9 years ago

This is great. I can now replicate the issue much more easily with this file.

cnaude commented 9 years ago

@modwizcode when you get a chance please have a look at this. It's driving me crazy. The exception occurs due to a bug in the minecraft code itself. The workaround i was hoping for was just a try-catch but the exception is never caught.

Lunaphied commented 9 years ago

Sure thing.

EvilOlaf commented 9 years ago

Another one, maybe helpful

04:06:23] [Server thread/INFO]: [Scavenger] Economy disabled. Item recovery will be free.
[04:06:23] [Server thread/ERROR]: Error occurred while enabling Scavenger v1.6-34 (Is it up to date?)
java.lang.RuntimeException: An internal error occured.
    at com.comphenix.protocol.reflect.accessors.DefaultMethodAccessor.invoke(DefaultMethodAccessor.java:20) ~[?:?]
    at com.comphenix.protocol.utility.StreamSerializer.deserializeItemStack(StreamSerializer.java:111) ~[?:?]
    at com.comphenix.protocol.utility.StreamSerializer.deserializeItemStack(StreamSerializer.java:236) ~[?:?]
    at com.cnaude.scavenger.RestorationManager.load(RestorationManager.java:118) ~[?:?]
    at com.cnaude.scavenger.RestorationManager.<init>(RestorationManager.java:33) ~[?:?]
    at com.cnaude.scavenger.Scavenger.onEnable(Scavenger.java:75) ~[?:?]
    at org.bukkit.plugin.java.JavaPlugin.setEnabled(JavaPlugin.java:321) ~[craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at org.bukkit.plugin.java.JavaPluginLoader.enablePlugin(JavaPluginLoader.java:335) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at org.bukkit.plugin.SimplePluginManager.enablePlugin(SimplePluginManager.java:405) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at org.bukkit.craftbukkit.v1_8_R1.CraftServer.loadPlugin(CraftServer.java:356) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at org.bukkit.craftbukkit.v1_8_R1.CraftServer.enablePlugins(CraftServer.java:316) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at net.minecraft.server.v1_8_R1.MinecraftServer.q(MinecraftServer.java:402) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at net.minecraft.server.v1_8_R1.MinecraftServer.k(MinecraftServer.java:370) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at net.minecraft.server.v1_8_R1.MinecraftServer.a(MinecraftServer.java:325) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at net.minecraft.server.v1_8_R1.DedicatedServer.init(DedicatedServer.java:211) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at net.minecraft.server.v1_8_R1.MinecraftServer.run(MinecraftServer.java:494) [craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at java.lang.Thread.run(Unknown Source) [?:1.7.0_71]
Caused by: java.io.IOException: Root tag must be a named compound tag
    at net.minecraft.server.v1_8_R1.NBTCompressedStreamTools.a(NBTCompressedStreamTools.java:62) ~[craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at net.minecraft.server.v1_8_R1.PacketDataSerializer.h(PacketDataSerializer.java:161) ~[craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at net.minecraft.server.v1_8_R1.PacketDataSerializer.i(PacketDataSerializer.java:196) ~[craftbukkit.jar:git-Spigot-952179b-bc03b6f]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.7.0_71]
    at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[?:1.7.0_71]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.7.0_71]
    at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.7.0_71]
    at com.comphenix.protocol.reflect.accessors.DefaultMethodAccessor.invoke(DefaultMethodAccessor.java:16) ~[?:?]
    ... 16 more

http://www.xup.in/dl,10884662/ignores.ser/ http://www.xup.in/dl,11914998/inv1.ser/

Lunaphied commented 9 years ago

Sorry haven't had time to look at this yet, will get to it this week.

cnaude commented 9 years ago

It looks like things are working a little better with the latest ProtocolLib and Spigot. Scavenger is now successfully catching the exception. On Mar 1, 2015 11:36 AM, "Starbuck Johnson" notifications@github.com wrote:

Sorry haven't had time to look at this yet, will get to it this week.

— Reply to this email directly or view it on GitHub https://github.com/cnaude/Scavenger/issues/10#issuecomment-76623011.

Lunaphied commented 9 years ago

I guess this can be closed then.

EvilOlaf commented 9 years ago

Till now it runs fine with 1.6-34. I'll update if another fail happens.

cnaude / Scavenger

Occasionally loading fails #10