Crash when respawning with 0 hunger.

Question

Crash when respawning with 0 hunger.

Delfil opened this issue 10 years ago · 14 comments

The game crashes when I try to respawn with 0 hunger while an other mod keeps the hunger at 0 after respawning.
I'm using the tinker construct mod setting:
B:"Keep hunger on death"=true
I'm using:
Forge 1.7.10-10.13.0.1180
SpiceOfLife-mc1.7x.1.1.0

[15:42:20] [Server thread/WARN]: Failed to handle packet for /127.0.0.1:60634
java.lang.ArithmeticException: / by zero
at java.math.BigDecimal.divideAndRound(Unknown Source) ~[?:1.7.0_60]
at java.math.BigDecimal.divide(Unknown Source) ~[?:1.7.0_60]
at java.math.BigDecimal.divide(Unknown Source) ~[?:1.7.0_60]
at com.udojava.evalex.Expression$6.eval(Expression.java:522) ~[Expression$6.class:?]
at com.udojava.evalex.Expression.eval(Expression.java:881) ~[Expression.class:?]
at squeek.spiceoflife.foodtracker.FoodModifier.getFoodModifier(FoodModifier.java:49) ~[FoodModifier.class:?]
at squeek.spiceoflife.asm.Hooks.getModifiedFoodValues(Hooks.java:57) ~[Hooks.class:?]
at net.minecraft.util.FoodStats.addStats(FoodStats.java:29) ~[FoodStats.class:?]
at tconstruct.armor.player.TPlayerHandler.onPlayerRespawn(TPlayerHandler.java:230) ~[TPlayerHandler.class:?]
at tconstruct.armor.player.TPlayerHandler.onPlayerRespawn(TPlayerHandler.java:58) ~[TPlayerHandler.class:?]
at cpw.mods.fml.common.eventhandler.ASMEventHandler_16_TPlayerHandler_onPlayerRespawn_PlayerRespawnEvent.invoke(.dynamic) ~[?:?]
at cpw.mods.fml.common.eventhandler.ASMEventHandler.invoke(ASMEventHandler.java:51) ~[ASMEventHandler.class:?]
at cpw.mods.fml.common.eventhandler.EventBus.post(EventBus.java:122) ~[EventBus.class:?]
at cpw.mods.fml.common.FMLCommonHandler.firePlayerRespawnEvent(FMLCommonHandler.java:559) ~[FMLCommonHandler.class:?]
at net.minecraft.server.management.ServerConfigurationManager.respawnPlayer(ServerConfigurationManager.java:515) ~[ServerConfigurationManager.class:?]
at net.minecraft.network.NetHandlerPlayServer.processClientStatus(NetHandlerPlayServer.java:919) ~[NetHandlerPlayServer.class:?]
at net.minecraft.network.play.client.C16PacketClientStatus.processPacket(C16PacketClientStatus.java:42) ~[C16PacketClientStatus.class:?]
at net.minecraft.network.play.client.C16PacketClientStatus.processPacket(C16PacketClientStatus.java:55) ~[C16PacketClientStatus.class:?]
at net.minecraft.network.NetworkManager.processReceivedPackets(NetworkManager.java:247) ~[NetworkManager.class:?]
at net.minecraft.network.NetworkSystem.networkTick(NetworkSystem.java:182) [NetworkSystem.class:?]
at net.minecraft.server.MinecraftServer.updateTimeLightAndEntities(MinecraftServer.java:736) [MinecraftServer.class:?]
at net.minecraft.server.dedicated.DedicatedServer.updateTimeLightAndEntities(DedicatedServer.java:350) [DedicatedServer.class:?]
at net.minecraft.server.MinecraftServer.tick(MinecraftServer.java:624) [MinecraftServer.class:?]
at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:495) [MinecraftServer.class:?]
at net.minecraft.server.MinecraftServer$2.run(MinecraftServer.java:762) [MinecraftServer$2.class:?]
[15:42:20] [Server thread/INFO]: Player lost connection: TextComponent{text='Internal server error', siblings=[], style=Style{hasParent=false, color=null, bold=null, italic=null, underlined=null, obfuscated=null, clickEvent=null, hoverEvent=null}}

Delfil · Answer 1 · 2014-07-21T15:50:41.000Z

It has something to do with my config?:
S:food.modifier.formula=MAX(MAX(0, (1 - count/12))^MIN(8, food_hunger_value)-1/5+200/(1000 + total_food_eaten), 0)

MAX(0, (1 - count/12))^MIN(8, food_hunger_value)) -> works fine.
MAX(MAX(0, (1 - count/12))^MIN(8, food_hunger_value+1)-1/5+200/(1000 + 10), 0) -> works fine too
S:food.modifier.formula=MAX(MAX(0, (1 - count/12))^MIN(8, food_hunger_value+1)-1/5+200/(1000 + total_food_eaten), 0) -> crash
MAX(MAX(0, (1 - count/12))^MIN(8, food_hunger_value+1)-1/5+200/(1000 + 10), 0) -> works fine too
S:food.modifier.formula=MAX(MAX(0, (1 - count/12))^MIN(8, food_hunger_value+1)-1/5+200/(1000 + MAX(0, total_food_eaten)), 0) -> crash

squeek502 · Answer 2 · 2014-07-21T18:21:41.000Z

By the way, were these crashes on a server with other people?

Delfil · Answer 3 · 2014-07-21T18:40:58.000Z

Thanks!
It was a test setup with a dedicated server & client. The server kept running, but the client was kicked. I also tried it without dedicated server and the client crashed, giving an error which seemed to be identical. Reloging & using the respawn button keeps kicking the client, same with single player worlds, so I had to restart the server with new configs to relog. I haven't tried this with multiple clients on yet, but I could try it out if you want?

squeek502 · Answer 4 · 2014-07-21T18:11:44.000Z

There's two things going on here.

0 to a negative power is undefined and will always trigger a divide by zero error.
It seems that the food eaten is not being reset on death, and therefore the food modifier is being applied to the addStats (with negative values) call by Tinkers Construct when it shouldn't.

So, I think the crash is actually based on whether or not count == 12 rather than anything to do with differences between the formulas.

I should have a fix for this soon. For now, you could wrap the MIN(8, food_hunger_value+1) part in a MAX like so: MAX(0, MIN(8, food_hunger_value+1))

Delfil · Answer 5 · 2014-07-21T21:25:23.000Z

Hunger Overhaul isn't working for me in 1.7.10.

During the testing I was only eating rotten flesh to speed up the progress, nothing else in my food history.

What I'm doing: eating some rotten flesh until I'm out of hunger points, then I wait till I die. When I click respawn the server gives me an error and kicks me out.

Config of SpiceOfLife: http://pastebin.com/mxZSHMsc

Installed mods:
Applied Energistics 2-rv1-alpha-11
CodeChickenCore-1.7.10-1.0.2.11
Mantle_mc1.7.10_0.3.0 (Comes with TConstruct)
NotEnoughItems-1.7.2.10-1.0.2.15
Pam's HarvestCraft 1.7.10a
SpiceOfLife-mc1.7.x-1.1.0
TConstruct_mc17.10_1.6.0d34
& a mod I'm working on. (has nothing to do with food)

This error was hard to reproduce, I had to die a few times with the same settings to get the error again, here is my server log:
[23:04:03] [Server thread/INFO]: Done (4.980s)! For help, type "help" or "?"
cut
[23:04:48] [Server thread/INFO]: Delfil[/127.0.0.1:51707] logged in with entity id 430 at (1.5, 64.0, -7.5)
[23:04:48] [Server thread/INFO]: Delfil joined the game
[23:05:45] [Server thread/INFO]: Delfil starved to death
[23:06:00] [Server thread/INFO]: [Delfil: Given [Rotten Flesh] * 64 to Delfil]
[23:08:29] [Server thread/INFO]: Delfil starved to death
[23:09:51] [Server thread/INFO]: Delfil starved to death
[23:09:52] [Server thread/WARN]: Failed to handle packet for /127.0.0.1:51707
java.lang.ArithmeticException: / by zero
at java.math.BigDecimal.divideAndRound(Unknown Source) ~[?:1.7.0_60]
at java.math.BigDecimal.divide(Unknown Source) ~[?:1.7.0_60]
at java.math.BigDecimal.divide(Unknown Source) ~[?:1.7.0_60]
at com.udojava.evalex.Expression$6.eval(Expression.java:522) ~[Expression$6.class:?]
at com.udojava.evalex.Expression.eval(Expression.java:881) ~[Expression.class:?]
at squeek.spiceoflife.foodtracker.FoodModifier.getFoodModifier(FoodModifier.java:49) ~[FoodModifier.class:?]
at squeek.spiceoflife.asm.Hooks.getModifiedFoodValues(Hooks.java:57) ~[Hooks.class:?]
at net.minecraft.util.FoodStats.addStats(FoodStats.java:29) ~[FoodStats.class:?]
at tconstruct.armor.player.TPlayerHandler.onPlayerRespawn(TPlayerHandler.java:230) ~[TPlayerHandler.class:?]
at tconstruct.armor.player.TPlayerHandler.onPlayerRespawn(TPlayerHandler.java:58) ~[TPlayerHandler.class:?]
at cpw.mods.fml.common.eventhandler.ASMEventHandler_11_TPlayerHandler_onPlayerRespawn_PlayerRespawnEvent.invoke(.dynamic) ~[?:?]
at cpw.mods.fml.common.eventhandler.ASMEventHandler.invoke(ASMEventHandler.java:51) ~[ASMEventHandler.class:?]
at cpw.mods.fml.common.eventhandler.EventBus.post(EventBus.java:122) ~[EventBus.class:?]
at cpw.mods.fml.common.FMLCommonHandler.firePlayerRespawnEvent(FMLCommonHandler.java:559) ~[FMLCommonHandler.class:?]
at net.minecraft.server.management.ServerConfigurationManager.respawnPlayer(ServerConfigurationManager.java:515) ~[ServerConfigurationManager.class:?]
at net.minecraft.network.NetHandlerPlayServer.processClientStatus(NetHandlerPlayServer.java:919) ~[NetHandlerPlayServer.class:?]
at net.minecraft.network.play.client.C16PacketClientStatus.processPacket(C16PacketClientStatus.java:42) ~[C16PacketClientStatus.class:?]
at net.minecraft.network.play.client.C16PacketClientStatus.processPacket(C16PacketClientStatus.java:55) ~[C16PacketClientStatus.class:?]
at net.minecraft.network.NetworkManager.processReceivedPackets(NetworkManager.java:247) ~[NetworkManager.class:?]
at net.minecraft.network.NetworkSystem.networkTick(NetworkSystem.java:182) [NetworkSystem.class:?]
at net.minecraft.server.MinecraftServer.updateTimeLightAndEntities(MinecraftServer.java:736) [MinecraftServer.class:?]
at net.minecraft.server.dedicated.DedicatedServer.updateTimeLightAndEntities(DedicatedServer.java:350) [DedicatedServer.class:?]
at net.minecraft.server.MinecraftServer.tick(MinecraftServer.java:624) [MinecraftServer.class:?]
at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:495) [MinecraftServer.class:?]
at net.minecraft.server.MinecraftServer$2.run(MinecraftServer.java:762) [MinecraftServer$2.class:?]
[23:09:52] [Server thread/INFO]: Delfil lost connection: TextComponent{text='Internal server error', siblings=[], style=Style{hasParent=false, color=null, bold=null, italic=null, underlined=null, obfuscated=null, clickEvent=null, hoverEvent=null}}
[23:09:52] [Server thread/INFO]: Delfil left the game

squeek502 · Answer 6 · 2014-07-21T20:27:31.000Z

I can't seem to reproduce the crash. Could you give more details about how you caused it? Things like all of your Spice of Life server config settings, how you are dying/respawning, what food you had eaten, if you have Hunger Overhaul installed, etc; as much information as you can give me would be helpful.

I can't really figure out how this is possible unless you eat something and respawn on the exact same server tick.

squeek502 · Answer 7 · 2014-07-21T23:19:28.000Z

I really can't figure out how this is possible. Does the mod you're working on alter world time in some way?

Somehow the following condition has to be returning true, but it doesn't seem possible unless you eat something on the same exact tick that you respawn (which itself seems impossible), or if the world time moves backwards somehow:

(lastEatingPlayer.worldObj.getWorldTime() - lastTimeEaten) <= 0

Delfil · Answer 8 · 2014-07-22T11:46:28.000Z

My mod just adds a few blocks & gui s, nothing special.

I added a few lines to print out the variables.
Class: squeek.spiceoflife.foodtracker.FoodModifier
Function: public static float getFoodModifier(EntityPlayer player, ItemStack food, FoodStats foodStats, int hunger, float saturationModifier)
At line 48

[12:58:46] [Server thread/INFO]: Delfil starved to death
count: 20
historySize: 20
hunger: -14
saturationModifier: 0.0
foodStats.getFoodLevel(): 20
foodStats.getSaturationLevel(): 5.0
totalFoodsEaten: 98
[12:58:48] [Server thread/WARN]: Failed to handle packet for /127.0.0.1:58485
java.lang.ArithmeticException: / by zero
etc

After re-logging & trying to respawn again, the numbers stay the same except for the hunger value, who changes to -20. After that the numbers won't change again. I tried this 2 times, both hunger values started at -14 and the 2nd time and times after that the hunger value was -20.

So the hunger is somehow negative.., I can't really find where this value is calculated. But it seems unlikely if it has something to do with lastTimeEaten?
If it does, the problem probably comes from somewhere else.

squeek502 · Answer 9 · 2014-07-22T20:01:35.000Z

The hunger being negative is expected. TConstruct uses player.getFoodStats().addStats(-(20 - savedhunger), 0) to set the hunger to its previous level after respawning.

The problem here is that getFoodModifier should ignore that addStats call because you didn't eat anything on the same tick that the negative hunger is added. If you can consistently get the crash, add a line that prints:

lastEatingPlayer.worldObj.getWorldTime() - lastTimeEaten

I'm expecting that to be negative, which makes no sense, as it implies time travel.

EDIT: Actually, print each separately; that might give more information

ModSpiceOfLife.Log.info("worldTime: " + lastEatingPlayer.worldObj.getWorldTime());
ModSpiceOfLife.Log.info("lastTimeEaten: " + lastTimeEaten);

squeek502 · Answer 10 · 2014-10-10T02:21:59.000Z

Closing. It shouldn't be an issue in the 1.7.10 version and, until it can be reproduced, it'll have to go unfixed in the 1.6.4/1.7.2 versions.

Delfil · Answer 11 · 2014-07-24T12:53:30.000Z

Where do you want me to put that?

squeek502 · Answer 12 · 2014-07-24T17:20:04.000Z

In squeek.spiceoflife.asm.Hooks.getModifiedFoodValues(). But here's a built version that already has those modifications: SpiceOfLife-mc1.7.2-1.1.0-test.jar

The code added:

ModSpiceOfLife.Log.info("worldObj: " + lastEatingPlayer.worldObj);
ModSpiceOfLife.Log.info("worldTime: " + lastEatingPlayer.worldObj.getWorldTime());
ModSpiceOfLife.Log.info("lastTimeEaten: " + lastTimeEaten);
ModSpiceOfLife.Log.info("deltaTime: " + (lastEatingPlayer.worldObj.getWorldTime() - lastTimeEaten));
ModSpiceOfLife.Log.info("lastEatingPlayer: " + lastEatingPlayer);
ModSpiceOfLife.Log.info("lastFoodEaten: " + lastFoodEaten);

Also, using this formula might make it easier to recreate the crash:

0^food_hunger_value

squeek502 · Answer 13 · 2014-07-26T14:43:42.000Z

Well, if you get it again, let me know, but deltaTime being zero is expected when you are actually eating something. It's only a problem if deltaTime is <= 0 and you didn't eat something on that tick.

Anyway, the 1.7.10 version of the mod will be changing quite a bit as I'm going to be moving the mod over to use the AppleCore API I've been working on for Hunger Overhaul, and this bug will not be possible once I make that switch, because AppleCore will no longer hook into the version of FoodStats.addStats that is causing this.

Delfil · Answer 14 · 2014-07-26T11:31:33.000Z

I can't reproduce the crash anymore with your test.jar
But I got this:
[13:19:44] [Server thread/INFO]: Delfil starved to death
[13:19:46] [Server thread/INFO] [SpiceOfLife]: worldObj: net.minecraft.world.WorldServer@3a547a96
[13:19:46] [Server thread/INFO] [SpiceOfLife]: worldTime: 1000
[13:19:46] [Server thread/INFO] [SpiceOfLife]: lastTimeEaten: 1000
[13:19:46] [Server thread/INFO] [SpiceOfLife]: deltaTime: 0
[13:19:46] [Server thread/INFO] [SpiceOfLife]: lastEatingPlayer: EntityPlayerMP['Delfil'/7348, l='world', x=4.50, y=64.00, z=2.50]
[13:19:46] [Server thread/INFO] [SpiceOfLife]: lastFoodEaten: 61xitem.rottenFlesh@0

Share to