Alexthw46 / Ars-Elemental

Add-on to Ars Nouveau, based on elemental stuff
https://www.curseforge.com/minecraft/mc-mods/ars-elemental-elemental-spell-foci
GNU General Public License v3.0
3 stars 5 forks source link

[1.16.5] Invalid spell cast found! This is a bug and should be reported! #56

Closed CactusPuppy closed 3 months ago

CactusPuppy commented 3 months ago

I am running a Roguelike Adventures and Dungeons 2 modpack (v1.9) server on 1.16.5. While doing so, I have noticed the following output in the server logs.

Expand for server log snippet ``` [05Apr2024 18:37:30.594] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:49]: ======= [05Apr2024 18:37:30.594] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:50]: Invalid spell cast found! This is a bug and should be reported! [05Apr2024 18:37:30.594] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:51]: Projectile -> Conjure Terrain -> AOE x7 -> Pierce [05Apr2024 18:37:30.594] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:52]: Casting player: [05Apr2024 18:37:30.594] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:53]: ServerPlayerEntity['CloudedDarkness'/191261, l='ServerLevel[world]', x=1136.74, y=10.00, z=351.59] [05Apr2024 18:37:30.594] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:54]: Casting tile: [05Apr2024 18:37:30.594] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:55]: null [05Apr2024 18:37:30.594] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:56]: ======= [05Apr2024 18:37:30.594] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: java.lang.IndexOutOfBoundsException: Index: 10, Size: 10 [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at java.util.ArrayList.rangeCheck(ArrayList.java:659) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at java.util.ArrayList.get(ArrayList.java:435) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.api.spell.SpellContext.nextSpell(SpellContext.java:47) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.api.spell.SpellResolver.resolveEffects(SpellResolver.java:142) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.api.spell.SpellResolver.onResolveEffect(SpellResolver.java:128) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.common.entity.EntityProjectileSpell.func_70227_a(EntityProjectileSpell.java:236) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.common.entity.EntityProjectileSpell.func_70071_h_(EntityProjectileSpell.java:103) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.world.server.ServerWorld.func_217479_a(ServerWorld.java:611) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.teampotato.doespotatotick.util.tick.DoTickUtil.guardEntityTickVanilla(DoTickUtil.java:54) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.world.World.func_217390_a(World.java:2690) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.world.server.ServerWorld.func_72835_b(ServerWorld.java:404) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_71190_q(MinecraftServer.java:851) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.dedicated.DedicatedServer.func_71190_q(DedicatedServer.java:291) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_71217_p(MinecraftServer.java:787) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_240802_v_(MinecraftServer.java:642) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_240783_a_(MinecraftServer.java:232) [05Apr2024 18:37:30.595] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at java.lang.Thread.run(Thread.java:748) ```

Looking back through the logs, I found another instance of a similar error being logged, and so as to provide as much information as possible, I am including it below as well

Expand for server log snippet ``` [15:35:02] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:49]: ======= [15:35:02] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:50]: Invalid spell cast found! This is a bug and should be reported! [15:35:02] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:51]: Projectile -> Conjure Terrain -> AOE x4 -> Pierce x4 [15:35:02] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:52]: Casting player: [15:35:02] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:53]: ServerPlayerEntity['RuaMoku'/395992, l='ServerLevel[world]', x=1690.07, y=1.00, z=-83.68] [15:35:02] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:54]: Casting tile: [15:35:02] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:55]: null [15:35:02] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:56]: ======= [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: java.lang.IndexOutOfBoundsException: Index: 10, Size: 10 [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at java.util.ArrayList.rangeCheck(ArrayList.java:659) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at java.util.ArrayList.get(ArrayList.java:435) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.api.spell.SpellContext.nextSpell(SpellContext.java:47) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.api.spell.SpellResolver.resolveEffects(SpellResolver.java:142) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.api.spell.SpellResolver.onResolveEffect(SpellResolver.java:128) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.common.entity.EntityProjectileSpell.func_70227_a(EntityProjectileSpell.java:236) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.common.entity.EntityProjectileSpell.func_70071_h_(EntityProjectileSpell.java:103) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.world.server.ServerWorld.func_217479_a(ServerWorld.java:611) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.teampotato.doespotatotick.util.tick.DoTickUtil.guardEntityTickVanilla(DoTickUtil.java:54) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.world.World.func_217390_a(World.java:2690) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.world.server.ServerWorld.func_72835_b(ServerWorld.java:404) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_71190_q(MinecraftServer.java:851) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.dedicated.DedicatedServer.func_71190_q(DedicatedServer.java:291) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_71217_p(MinecraftServer.java:787) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_240802_v_(MinecraftServer.java:642) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_240783_a_(MinecraftServer.java:232) [15:35:02] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at java.lang.Thread.run(Thread.java:748) ```

In both cases, the error message was repeated several times over the course of a few minutes, presumably due to the players casting the spell multiple times. Players reported to me that the spell appeared to have worked as intended.

After digging around a bit, I found Ars-Noveau #710, which more or less precisely described the error I was seeing. Reading through the conversation, I double-checked that the linked mod version (presumably which fixed the bug) was the version we were using (see version information below), and seeing as the issue tracker indicated the bug was with Ars Elemental, I decided to open the issue here instead of under Ars Noveau's repository. Please let me know if this issue should be moved and I'll be happy to do so.

Version Information

MC Version: 1.16.5 Forge Version: 1.16.5-36.2.34 Ars Noveau Version: 1.16.5-1.25.10 Ars Elemental Version: 1.16.5-0.1.6.4

Alexthw46 commented 3 months ago

Just to make sure, will it happen only with a full spell? The error is probably simple but it's mostly harmless and more importantly 1.16.5 is no longer supported so I'm not sure if this will be fixed, setting up an old env is for some reasons extremely time consuming

CactusPuppy commented 3 months ago

The error does seem to be loosely correlated with some kind of issue which causes players to lose levels in Mining in Project MMO, and the mining level reset has not been seen outside of using projectiles. I'll try and collect more information, but looking deeper, I do not think the Project MMO mining level resets are due to this mod, so I'll close this issue for now unless more information arises which would indicate this mod is at fault.

CactusPuppy commented 3 months ago

Just to make sure, will it happen only with a full spell? The error is probably simple but it's mostly harmless and more importantly 1.16.5 is no longer supported so I'm not sure if this will be fixed, setting up an old env is for some reasons extremely time consuming

And just to answer this question, it appears to happen when Conjure Terrain is used with any amount of AOE, even if the form is not projectile and the spell is not full.

Example server log snippet ``` [00:30:43] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:49]: ======= [00:30:43] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:50]: Invalid spell cast found! This is a bug and should be reported! [00:30:43] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:51]: Underfoot -> Conjure Terrain -> AOE [00:30:43] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:52]: Casting player: [00:30:43] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:53]: ServerPlayerEntity['CactusPuppy'/241016, l='ServerLevel[world]', x=1061.37, y=95.44, z=200.93] [00:30:43] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:54]: Casting tile: [00:30:43] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:55]: null [00:30:43] [Server thread/INFO] [STDOUT/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:56]: ======= [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: java.lang.IndexOutOfBoundsException: Index: 3, Size: 3 [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at java.util.ArrayList.rangeCheck(ArrayList.java:659) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at java.util.ArrayList.get(ArrayList.java:435) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.api.spell.SpellContext.nextSpell(SpellContext.java:47) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.api.spell.SpellResolver.resolveEffects(SpellResolver.java:142) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.api.spell.SpellResolver.onResolveEffect(SpellResolver.java:128) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.common.spell.method.MethodUnderfoot.onCast(MethodUnderfoot.java:33) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.api.spell.SpellResolver.onCast(SpellResolver.java:109) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at com.hollingsworth.arsnouveau.common.items.SpellBook.func_77659_a(SpellBook.java:149) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.item.ItemStack.func_77957_a(ItemStack.java:216) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.management.PlayerInteractionManager.func_187250_a(PlayerInteractionManager.java:287) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.network.play.ServerPlayNetHandler.func_147346_a(ServerPlayNetHandler.java:982) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.network.play.client.CPlayerTryUseItemPacket.func_148833_a(SourceFile:31) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.network.play.client.CPlayerTryUseItemPacket.func_148833_a(SourceFile:9) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.network.PacketThreadUtil.func_225383_a(SourceFile:21) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.util.concurrent.TickDelayedTask.run(SourceFile:18) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.util.concurrent.ThreadTaskExecutor.func_213166_h(SourceFile:144) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.util.concurrent.RecursiveEventLoop.func_213166_h(SourceFile:23) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_213166_h(MinecraftServer.java:734) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_213166_h(MinecraftServer.java:159) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.util.concurrent.ThreadTaskExecutor.func_213168_p(SourceFile:118) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_213205_aW(MinecraftServer.java:717) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_213168_p(MinecraftServer.java:711) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.util.concurrent.ThreadTaskExecutor.func_213161_c(SourceFile:127) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_213202_o(MinecraftServer.java:697) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_240802_v_(MinecraftServer.java:646) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at net.minecraft.server.MinecraftServer.func_240783_a_(MinecraftServer.java:232) [00:30:43] [Server thread/INFO] [STDERR/]: [com.hollingsworth.arsnouveau.api.spell.SpellContext:nextSpell:57]: at java.lang.Thread.run(Thread.java:748) ```