[Resolved] Player with Journal joins, PlayerJoinEvent & Generated Exception errors
Formula350 opened this issue ยท 5 comments
NOTE: I still felt it worthwhile to bring this to your attention, but half way through making this report I realized what triggered the error/s to occur in the first place. Whether or not they materialized as a result of the player having a Journal, and that it would've been handled differently (quietly?) had they NOT, I can only speculate on.
My best guess is that after I had changed a quest yesterday (which this player has) and removed a portion of the stage, that because the player had a Journal it somehow prevented Quests from forcing the player to quit said quest because it had been altered and no longer matched what was in their Data file. I _believe_ this is what occurs when a player usually joins and quest/s they're on have changed, seeing as we have made changes in the past and this error-spam hasn't occurred.
*Based on past experience with Quests and the PlayerJoinEvent issues, I know that all is needed is for me to fix the entry in the the player Data file/s (if multiple players) which have the offending quest/s. I can do it quick and easy by deleting the player file, which is unfair to the player in my opinion; deleting the entire quest from their file, but is also unfair since they'll lose their quest progress; or to correct the specific portion that is mismatched from the quest/s in their current state, which in this case means simply removing the item-delivery-amounts
line (and adjusting the stage if needed). *
_We now return you to our regularly scheduled broadcast_
Using: Quests build 76 (unfortunately I had yet to enable Debug in the config)
Chain of events... Things were working fine today until a player joined, causing Quests to freak out afterwards with an "Unable to pass PlayerJoinEvent" , and then with the Task ## error right up until the moment I unloaded the plugin.
The initial join error (one I had not seen for a very very long time!):
[12:54:29] [User Authenticator #70/INFO]: UUID of player LarisaGeekyGreek is bd2562ae-9a75-4f12-966f-814a10511187
[12:54:29] [Server thread/INFO]: LarisaGeekyGreek[/-IP OMITTED-] logged in with entity id 403584 at ([world] -1919.452530786104, 63.0, -1703.5685376954013)
[12:54:29] [Server thread/ERROR]: Could not pass event PlayerJoinEvent to Quests v2.4.0
org.bukkit.event.EventException
at org.bukkit.plugin.java.JavaPluginLoader$1.execute(JavaPluginLoader.java:297) ~[craftbukkit_dev.jar:git-Bukkit-33d5de3]
at org.bukkit.plugin.RegisteredListener.callEvent(RegisteredListener.java:62) ~[craftbukkit_dev.jar:git-Bukkit-33d5de3]
at org.bukkit.plugin.TimedRegisteredListener.callEvent(TimedRegisteredListener.java:36) ~[craftbukkit_dev.jar:git-Bukkit-33d5de3]
at org.bukkit.plugin.SimplePluginManager.fireEvent(SimplePluginManager.java:501) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
at org.bukkit.plugin.SimplePluginManager.callEvent(SimplePluginManager.java:486) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
at net.minecraft.server.v1_8_R1.PlayerList.onPlayerJoin(PlayerList.java:258) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
at net.minecraft.server.v1_8_R1.PlayerList.a(PlayerList.java:142) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
at net.minecraft.server.v1_8_R1.LoginListener.b(LoginListener.java:81) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
at net.minecraft.server.v1_8_R1.LoginListener.c(LoginListener.java:41) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
at net.minecraft.server.v1_8_R1.NetworkManager.a(NetworkManager.java:150) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
at net.minecraft.server.v1_8_R1.ServerConnection.c(SourceFile:151) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
at net.minecraft.server.v1_8_R1.MinecraftServer.z(MinecraftServer.java:733) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
at net.minecraft.server.v1_8_R1.DedicatedServer.z(DedicatedServer.java:284) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
at net.minecraft.server.v1_8_R1.MinecraftServer.y(MinecraftServer.java:609) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
at net.minecraft.server.v1_8_R1.MinecraftServer.run(MinecraftServer.java:517) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
at java.lang.Thread.run(Thread.java:745) [?:1.7.0_72]
Caused by: java.lang.NullPointerException
at me.blackvein.quests.Quester.getObjectivesReal(Quester.java:410) ~[?:?]
at me.blackvein.quests.Quester.updateJournal(Quester.java:289) ~[?:?]
at me.blackvein.quests.Quester$1.put(Quester.java:51) ~[?:?]
at me.blackvein.quests.Quester$1.put(Quester.java:44) ~[?:?]
at me.blackvein.quests.Quester.loadData(Quester.java:2582) ~[?:?]
at me.blackvein.quests.PlayerListener.onPlayerJoin(PlayerListener.java:845) ~[?:?]
at sun.reflect.GeneratedMethodAccessor668.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.7.0_72]
at java.lang.reflect.Method.invoke(Method.java:606) ~[?:1.7.0_72]
at org.bukkit.plugin.java.JavaPluginLoader$1.execute(JavaPluginLoader.java:295) ~[craftbukkit_dev.jar:git-Bukkit-33d5de3]
... 15 more
Then this error is what continued to spam the console for the entire time, once every second up until I unloaded quests:
14.05 13:23:12 [Server] WARN Task #83 for Quests v2.4.0 generated an exception
14.05 13:23:12 [Server] INFO java.lang.NullPointerException
14.05 13:23:12 [Server] INFO at me.blackvein.quests.Quester.getObjectivesReal(Quester.java:410) ~[?:?]
14.05 13:23:12 [Server] INFO at me.blackvein.quests.Quester.updateJournal(Quester.java:289) ~[?:?]
14.05 13:23:12 [Server] INFO at me.blackvein.quests.Quester$1.put(Quester.java:51) ~[?:?]
14.05 13:23:12 [Server] INFO at me.blackvein.quests.Quester$1.put(Quester.java:44) ~[?:?]
14.05 13:23:12 [Server] INFO at me.blackvein.quests.Quester.loadData(Quester.java:2582) ~[?:?]
14.05 13:23:12 [Server] INFO at me.blackvein.quests.Quests.getQuester(Quests.java:2607) ~[?:?]
14.05 13:23:12 [Server] INFO at me.blackvein.quests.NpcEffectThread.run(NpcEffectThread.java:33) ~[?:?]
14.05 13:23:12 [Server] INFO at org.bukkit.craftbukkit.v1_8_R1.scheduler.CraftTask.run(CraftTask.java:53) ~[craftbukkit_dev.jar:git-Bukkit-33d5de3]
14.05 13:23:12 [Server] INFO at org.bukkit.craftbukkit.v1_8_R1.scheduler.CraftScheduler.mainThreadHeartbeat(CraftScheduler.java:349) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
14.05 13:23:12 [Server] INFO at net.minecraft.server.v1_8_R1.MinecraftServer.z(MinecraftServer.java:668) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
14.05 13:23:12 [Server] INFO at net.minecraft.server.v1_8_R1.DedicatedServer.z(DedicatedServer.java:284) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
14.05 13:23:12 [Server] INFO at net.minecraft.server.v1_8_R1.MinecraftServer.y(MinecraftServer.java:609) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
14.05 13:23:12 [Server] INFO at net.minecraft.server.v1_8_R1.MinecraftServer.run(MinecraftServer.java:517) [craftbukkit_dev.jar:git-Bukkit-33d5de3]
14.05 13:23:12 [Server] INFO at java.lang.Thread.run(Thread.java:745) [?:1.7.0_72]
The cause seems to be pretty clear that it was journal related, and a quick peek at their Data file does confirm the player having one:
currentQuests:
- Lost Hero
- Offering to Hades
currentStages:
- 1
- 0
quest-points: 3
questData:
Lost Hero:
item-delivery-amounts:
- 0
citizen-ids-killed:
- 750
citizen-amounts-killed:
- 0
Offering to Hades:
mobs-killed:
- Cow
mobs-killed-amounts:
- 25
sheep-to-shear:
- Black
sheep-sheared:
- 1
completed-Quests:
- Wild Boar Problems
- Polyphemus
- An incomplete collection
completedRedoableQuests:
- An incomplete collection
completedQuestTimes:
- 1431083670451
hasJournal: true
lastKnownName: LarisaGeekyGreek
Aaaaand I now see why this all happened in the first place... It may or may not be entirely the journal's fault, but I guess that would be for you to decide ๐
Why this happened was because yesterday I updated some quests, one of which did end up being _Lost Hero_, which as you can see this player has. What was changed on it is the item-delivery-amounts:
portion of the stage which we had added as a temporary work-around for a previous issue. Seems that when I updated the quest, the plugin was unable to handle the change fluidly, again a possible cause being this specific player has a Journal.
I considered closing this right away after posting but opted not to as I was unsure if it would alert you or not.
-Form
So, what should have happened when you updated the Lost Hero quest? Should item-delivery-amounts be something other than 0?
So, in a nutshell, player data/journal needs to be updated when a Quest is updated.
Looking further into this, it appears Quests attempts to do so, but fails. I will certainly come back to this at a later date.
This is how the quest's stage WAS:
stages:
ordered:
'1':
items-to-deliver:
- name-DIRT:amount-1
npc-delivery-ids:
- 752
delivery-messages:
- '*Thank You*'
'2':
npc-ids-to-kill:
- 750
npc-kill-amounts:
- 1
As you can see, it matches what the player's Data file looks like in my earlier post.
This is what it NOW is...
stages:
ordered:
'1':
npc-ids-to-kill:
- 750
npc-kill-amounts:
- 1
What causes Quests to flip out is the fact that when a player who was offline and has that quest before its delivery stage was removed entirely, their Data file does not get updated.
How I go about fixing it is to look through the console output and find when the errors start (assuming it is only 1 player causing errors), resolve their IGN to UUID, open up their Quests Data file, and execute one of the methods that I found to work: remove quest entirely, modify quest, or if needed delete their file entirely [I generally do not do this anymore thanks to having a better understanding of what causes issues]. All of these require the player to temporarily disconnect while I modify their file though, as reloading the plugin (via internal reload, or with PlugMan) only re-writes the player's Data file from the system's memory -- figuring that out took some trial and error, but sure does save time versus restarting the entire server!
To specifically answer your question...
The player's file data is correctly configured for Lost Hero _BEFORE_ the changes, and so "0" is simply reflecting the fact they had not delivered any items yet.
_However_, ultimately the answer is No. That player's questData section now should look like this:
questData:
Lost Hero:
citizen-ids-killed:
- 750
citizen-amounts-killed:
- 0
Offering to Hades:
mobs-killed:
- Cow
mobs-killed-amounts:
- 25
sheep-to-shear:
- Black
sheep-sheared:
- 1
And then also having the currentStages set to 0 instead of 1, since as I understand it a quest with 1 stage only is given a 0.
The only two suggestions I can think of to solve this in an automated fashion would be during either server Start or Shutdown the Quests plugin goes through all Data files, runs checks against their listed quest Names, Stages and each stage's Objectives. When a discrepancy is found, execute one of the following methods [Note: I do realize that this in general isn't very efficient, and also some of these may no doubt involve a lot of code]:
- If a quest's NAME has changed, but the other Objectives (deliveries, kills, etc) match entirely, then update the name of the quest but keep progress. Alternatively, if the Objectives are missing one or two but otherwise match 100% (i.e. Lost Hero had a delivery removed, but the same Kill Target was still in place), update the quest to reflect changes while keeping progress..
- If the Name changes or Delivery objectives are removed on a quest that the player has delivered ANY amount items, flag the quest to allow the player to regain their turned in items. Note: This may need Quests to keep an alternate log file of Deleted or Changed quests in order to call on in order to return items. Reasoning would be due to unique items (NBT, specific item datavalue, etc), so that they receive those back instead of a vanilla item. SUGGESTION: Often there are times when a player's inventory is full and Quests fails to deliver rewards. If this method is utilized I think that an inventory check should be executed before giving back the items delivered, whereby notifying the player their inventory is full, how many free-slots are required, and providing them a command they can run when when they've made room.
/quests deliver
maybe? [This would be of general benefit, non-exclusive to this] - Easiest, simply force the player in question to quit the quest or quests which are no longer a valid match. Again, worst case scenario given they'll lose all progress, but worst of all they may lose a lot of valuable items already delivered.
:sigh: I apologize, this was far far wordier than I had originally anticipated ๐ฆ
(Also I may have edit a portion and forgotten to delete what I changed, but I don't think so... Point is though, if anything reads as confusing, point it out and I'll clarify!)
-Form
lol Yea, in a nutshell, exactly that. Works just fine for online players, doesn't for those who are offline.
Sorry it turned out to be a more involved issue than I was thinking :
-Form