Funwayguy / BetterQuesting

MIT License
55 stars 98 forks source link

[Server-side issue] Quests disappear (?) {maybe bug} #470

Open Davoleo opened 5 years ago

Davoleo commented 5 years ago

I don't know if this is a bug, but when joining my server on FTB continuum I opened the quests and everything was gone, quests as well as sections

I tried removing the QuestDatabase so that it could be recreated by the mod after a server reboot, but it didn't work

I tried re-uploading the DefaultQuests file in the config folder in case it was corrupted but that didn't work

The only way I sorted this out for me was doing bq_admin default load and then manually complete every quest

The issue is that I can't do this for every player who plays in my server, furthermore I would need to make them operator one by one, and then let them manually complete all the quests

Lost the point of this issue, which is asking if there's a feature to make every user reload their quests (And yeah, I already asked them to run "bq_user refresh" )

Davoleo commented 5 years ago

( Side question: what anime is your avatar image from? ) 😅

Funwayguy commented 5 years ago

Odd that syncing failed completely. Is this using build 271? There's a user level command to resync client side quests without reloading everything from file:

/bq_user refresh

Avatar is Ernesti from the anime Knights & Magic.

Davoleo commented 5 years ago

It's using "BetterQuesting-3.5.266" I guess it's build 266 Maybe it's because the build is too old? In that modpack version

By the way I tried using bq_user refresh, but I doesn't seem to work

Funwayguy commented 5 years ago

Can you update to 271 to see if you can repeat the issue there? I believe some minor networking changes were made since then.

If client side refreshing isn't working then it's almost certainly messed up server side.

Davoleo commented 5 years ago

I updated the mod, but the issue remains anyway

Davoleo commented 5 years ago

Here's a screenshot of what's happening image

Warmad0311 commented 5 years ago

I am struggling with this exact same issue on my server, the same effect as Davoleo has posted. I am restoring the /world/betterquesting folder every other day. It works fine for a day or two then goes corrupt again.

Better Questing - 3.5.280 Enigmatia 2 Expert 1.47 Pack

Funwayguy commented 5 years ago

Is there any errors in the logs whenever this happens? I still can't seem to recreate this on my end.

Warmad0311 commented 5 years ago

Not sure this will help, the error is in the log on startup, when the file appears to be corrupt. I checked the logs prior to this one and it showed a clean server shutdown, so not a crash. When it started up again the file was corrupt.

[22:15:15] [pool-4-thread-1/ERROR] [betterquesting]: An error occured while loading JSON from file: com.google.gson.JsonSyntaxException: java.io.EOFException: End of input at line 105607 column 1 path $.questProgress:9.356:10.tasks:9.0:10.userProgress:9.30:10.uuid:8 at com.google.gson.Gson.fromJson(Gson.java:897) ~[Gson.class:?] at com.google.gson.Gson.fromJson(Gson.java:825) ~[Gson.class:?] at betterquesting.api.utils.JsonHelper.lambda$ReadFromFile$0(JsonHelper.java:170) ~[JsonHelper.class:?] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_181] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_181] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_181] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_181] Caused by: java.io.EOFException: End of input at line 105607 column 1 path $.questProgress:9.356:10.tasks:9.0:10.userProgress:9.30:10.uuid:8 at com.google.gson.stream.JsonReader.nextNonWhitespace(JsonReader.java:1393) ~[JsonReader.class:?] at com.google.gson.stream.JsonReader.doPeek(JsonReader.java:482) ~[JsonReader.class:?] at com.google.gson.stream.JsonReader.hasNext(JsonReader.java:414) ~[JsonReader.class:?] at com.google.gson.internal.bind.TypeAdapters$29.read(TypeAdapters.java:738) ~[TypeAdapters$29.class:?] at com.google.gson.internal.bind.TypeAdapters$29.read(TypeAdapters.java:739) ~[TypeAdapters$29.class:?] at com.google.gson.internal.bind.TypeAdapters$29.read(TypeAdapters.java:739) ~[TypeAdapters$29.class:?] at com.google.gson.internal.bind.TypeAdapters$29.read(TypeAdapters.java:739) ~[TypeAdapters$29.class:?] at com.google.gson.internal.bind.TypeAdapters$29.read(TypeAdapters.java:739) ~[TypeAdapters$29.class:?] at com.google.gson.internal.bind.TypeAdapters$29.read(TypeAdapters.java:739) ~[TypeAdapters$29.class:?] at com.google.gson.internal.bind.TypeAdapters$29.read(TypeAdapters.java:739) ~[TypeAdapters$29.class:?] at com.google.gson.internal.bind.TypeAdapters$29.read(TypeAdapters.java:714) ~[TypeAdapters$29.class:?] at com.google.gson.internal.bind.TypeAdapters$35$1.read(TypeAdapters.java:910) ~[TypeAdapters$35$1.class:?] at com.google.gson.Gson.fromJson(Gson.java:887) ~[Gson.class:?] ... 6 more [22:15:15] [pool-4-thread-1/ERROR] [betterquesting]: Creating backup at: /home/minecraft/multicraft/servers/server45409/./world/betterquesting/malformed_QuestProgress.json0.json [22:15:15] [Server thread/INFO] [betterquesting]: Loaded 702 quests [22:15:15] [Server thread/INFO] [betterquesting]: Loaded 21 quest lines [22:15:15] [Server thread/INFO] [betterquesting]: Loaded 6 parties [22:15:15] [Server thread/INFO] [betterquesting]: Loaded 41 names

Warmad0311 commented 5 years ago

Just an idea, what about double writing the progress file out. So that the mod can auto-recover the previous file on error. It's not a fix, but will make it survive errors.

1) Write QuestProgress.json 2) Call sync to ensure it written to disk 3) Write QuestProgress.json-backup 4) Call sync.

Then if it crashes while processing one of the files the previous one should be intact. Forgot to add on load failure, attempt to load the other file.

Davoleo commented 5 years ago

Talking about the original issue, and seeing the edited comment by @Funwayguy https://github.com/Funwayguy/BetterQuesting/issues/470#issuecomment-429885642 I guess the problem was server performance, this theory is also supported by the fact that the hosting service I had my server on was quite bad By now I can't reproduce my issue anymore, since I don't have that server anymore but, just as a warning for this new issue, remember that it could be some server side issues with your specific server

Thanks for all your help, and also on my side this issue can be closed

Funwayguy commented 5 years ago

Slowly getting somewhere with figuring this out. Changed some stuff to add additional safety catches in the event of failure to saving to file and this is getting triggered regularly: image

Now to figure out which other piece of code is messing with these files unexpectedly.

Note: Bigger databases and file system performance differences influence how often the IO collisions occur and the likely hood of corruption. I'm still working on tracking down all of the issues contributing to this.

EDIT: Oh boy this is looking a lot worse than I originally thought it was. Every attempt to save is firing these errors. BQ may have been performing unsafe reads and writes on hopes, dreams, and sheer dumb luck.

EDIT 2: Nope, 2 steps forward, one step back. Just messed up some code somewhere during rewrites throwing these errors. It is safer though.

Warmad0311 commented 5 years ago

Thanks for digging in to this, Based on your post it looks like it might be possibly conflicting with the backup mods. The backups usually calls /save-off prior to backing up, do you have protections to not save during this time? Just an idea.

Thanks again.

Funwayguy commented 5 years ago

Actually hadn't thought about the possibility of backups interfering. Would explain why some people have it regularly and others don't (and why I hear about it on servers more often).

Better Questing does adhere to the save on/off state however the actual reading and writing is offloaded to a separate thread. That means that if BQ schedules something on those files before a backup starts but doesn't finish immediately, both BQ and the backup may start reading/writing the same file with potentially nasty consequences like this. Build 182 has some extra safety against this now but I'm not sure if the mod(s) in charge of backups does and may continue its attempt anyway.