Weird local property issue

[lyn mimistrobell]

Hi,

 

For my mod I created a custom Capability that handles fuel burning (initial burn time, remaining burn time, etc.):

Spoiler

package net.mimistrobell.lyn.example.capabilities;

import net.mimistrobell.lyn.example.Logger;
import net.minecraft.init.Items;
import net.minecraft.item.ItemStack;
import net.minecraft.nbt.NBTTagCompound;
import net.minecraft.tileentity.TileEntityFurnace;
import net.minecraftforge.common.util.INBTSerializable;

public class FurnaceGeneratorHandler implements IFurnaceHandler, INBTSerializable<NBTTagCompound> {

  /**
   * For items with a vanilla burn time of 2000 ticks or more the initial burn time is set to 200
   * ticks, otherwise the initial burn time is set to 60 ticks.
   */
  private static final int VANILLA_BURNTIME_THRESHHOLD = 2000;
  private static final int BURN_TIME_LOW = 60;
  private static final int BURN_TIME_HIGH = 200;



  /** The current fuel item */
  private static final String NBT_FUEL_ITEM = "fuelItem";

  private ItemStack fuelItem = ItemStack.EMPTY;



  /** The remaining burn time in ticks for the current fuel item. */
  private static final String NBT_REMAINING_BURN_TIME = "remainingBurnTime";

  private int remainingBurnTime = 0;


  /**
   * Returns the current fuel item.
   * 
   * @return The fuel item
   */
  @Override
  public ItemStack getFuelItem() {
    return this.fuelItem;
  }

  /**
   * Sets the fuel item, only fuel items or buckets are accepted and only if there is no current
   * fuel item.
   * 
   * @param fuelItemIn The ItemStack with the fuelItem.
   */
  @Override
  public void setFuelItem(final ItemStack fuelItemIn) {
    Logger.info("fuelItem: {}", fuelItemIn);
    if (!this.fuelItem.isEmpty() || fuelItemIn.isEmpty())
      return;
    if (!TileEntityFurnace.isItemFuel(fuelItemIn) && fuelItemIn.getItem() != Items.BUCKET)
      return;

    this.fuelItem = fuelItemIn.copy();
    this.fuelItem.setCount(1);
    this.remainingBurnTime = getInitialBurnTime();
    Logger.info("this.fuelItem: {}, initialBurnTime:{}", this.fuelItem, getInitialBurnTime());
  }



  /**
   * Returns the initial burn time in ticks for the fuel item.
   * 
   * @return The initial burn time
   */
  @Override
  public int getInitialBurnTime() {
    if (this.fuelItem.isEmpty())
      return 0;

    final int vanillaBurnTime = TileEntityFurnace.getItemBurnTime(this.fuelItem);
    return vanillaBurnTime < VANILLA_BURNTIME_THRESHHOLD ? BURN_TIME_LOW : BURN_TIME_HIGH;
  }

  /**
   * Returns the amount of Forge Energy generated per tick.
   * 
   * @return FE/t
   */
  public int getEnergyPerTick() {
    //Logger.info("fuelItem: {}", this.fuelItem);
    if (this.fuelItem.isEmpty())
      return 0;

    final int vanillaBurnTime = TileEntityFurnace.getItemBurnTime(this.fuelItem);
    final int energyPerTick = Math.round((float) vanillaBurnTime / (float) getInitialBurnTime());
    Logger.info("energyPerTick: {}, vanillaBurnTime: {}, initialBurnTime: {}", energyPerTick, vanillaBurnTime, getInitialBurnTime());
    return Math.round((float) vanillaBurnTime / (float) getInitialBurnTime());
  }



  /**
   * Returns true if there is a fuel item and there is burn time remaining.
   * 
   * @return True if burning
   */
  @Override
  public boolean isBurning() {
    return this.remainingBurnTime > 0;
  }

  /**
   * Returns the remaining burn time in ticks for the current fuel item.
   * 
   * @return The remaining burn time
   */
  @Override
  public int getRemainingBurnTime() {
    return this.remainingBurnTime;
  }

  /**
   * Decreases the remaining burn time with 1 tick.
   */
  public void decreaseRemainingBurnTime() {
    this.remainingBurnTime = Math.max(0, this.remainingBurnTime - 1);
    if (this.remainingBurnTime == 0) {
      Logger.info("Finished burning");
      this.fuelItem = ItemStack.EMPTY;
    }
  }

  /**
   * Returns the remaining burn time relative to the initial burn time; 0 is no time, 1 = full time.
   * 
   * @return The relative remaining burn time
   */
  public float getRelativeRemainingBurnTime() {
    if (this.remainingBurnTime == 0)
      return 0.0f;

    if (getInitialBurnTime() == 1)
      return 1.0f;

    return (float) this.remainingBurnTime / (float) getInitialBurnTime();

  }

  /**
   * Returns the spent burn time relative to the initial burn time; 0 is no time, 1 = full time.
   * 
   * @return The relative spent burn time
   */
  public float getRelativeSpentBurnTime() {
    return 1.0f - getRelativeRemainingBurnTime();
  }



  /**
   * Returns the properties of this Capability as Named Binary Tag.
   * 
   * {@see INBTSerializable}
   * 
   * @return The NBT
   */
  @Override
  public NBTTagCompound serializeNBT() {
    Logger.info("this.fuelItem={}", this.fuelItem);
    NBTTagCompound tag = new NBTTagCompound();
    tag.setTag(NBT_FUEL_ITEM, this.fuelItem.serializeNBT());
    tag.setInteger(NBT_REMAINING_BURN_TIME, this.remainingBurnTime);
    Logger.info("tag={}", tag);
    return tag;
  }

  /**
   * Sets the properties of this Capability from the Named Binary Tag.
   * 
   * {@see INBTSerializable}
   * 
   * @param tag The NBT
   */
  @Override
  public void deserializeNBT(NBTTagCompound tag) {
    Logger.info("tag={}", tag);
    if (tag.hasKey(NBT_FUEL_ITEM))
      this.fuelItem.deserializeNBT((NBTTagCompound) tag.getTag(NBT_FUEL_ITEM));
    Logger.info("this.fuelItem={}", this.fuelItem);
    this.remainingBurnTime = tag.getInteger(NBT_REMAINING_BURN_TIME);
  }

}

 

 

My TE calls setFuelItem with an ItemStack that has coal; the log shows that the coal was accepted:

[18:32:02] [Server thread/INFO] [RadioTools]: [TileEntityFurnaceGenerator.update] fuelItemStack: 1xtile.blockCoal@0
[18:32:02] [Server thread/INFO] [RadioTools]: [FurnaceGeneratorHandler.setFuelItem] fuelItem: 1xtile.blockCoal@0
[18:32:02] [Server thread/INFO] [RadioTools]: [FurnaceGeneratorHandler.setFuelItem] this.fuelItem: 1xtile.blockCoal@0, initialBurnTime:200

 

Next, sendBlockEntity calls TE.getUpdatePacket which calls TE.getUpdateTag which tries to get the NBT of my Handler, but for some reason this.fuelItem was reset:

[18:32:02] [Server thread/INFO] [RadioTools]: [FurnaceGeneratorHandler.serializeNBT] this.fuelItem=0xtile.air@0
[18:32:02] [Server thread/INFO] [RadioTools]: [FurnaceGeneratorHandler.serializeNBT] tag={remainingBurnTime:200,fuelItem:{id:"minecraft:air",Count:0b,Damage:0s}}

 

The only places where I expect the fuel to be updated are setFuelItem and decreaseRemainingBurnTime when it finished burning but that doesn't happen until 10 seconds later:

[18:32:12] [Server thread/INFO] [RadioTools]: [FurnaceGeneratorHandler.decreaseRemainingBurnTime] Finished burning

 

I'm probably missing something obvious but I right now I'm blinded and I can't find it...

The only other logging was from the client which (of course) deserialized a tag with fuelItem air; deserializeNBT is never called on the server.

 

Full log:

Spoiler

[18:32:02] [Server thread/INFO] [RadioTools]: [TileEntityFurnaceGenerator.update] fuelItemStack: 1xtile.blockCoal@0
[18:32:02] [Server thread/INFO] [RadioTools]: [FurnaceGeneratorHandler.setFuelItem] fuelItem: 1xtile.blockCoal@0
[18:32:02] [Server thread/INFO] [RadioTools]: [FurnaceGeneratorHandler.setFuelItem] this.fuelItem: 1xtile.blockCoal@0, initialBurnTime:200
[18:32:02] [Server thread/INFO] [RadioTools]: [FurnaceGeneratorHandler.serializeNBT] this.fuelItem=0xtile.air@0
[18:32:02] [Server thread/INFO] [RadioTools]: [FurnaceGeneratorHandler.serializeNBT] tag={remainingBurnTime:200,fuelItem:{id:"minecraft:air",Count:0b,Damage:0s}}
[18:32:02] [main/INFO] [RadioTools]: [FurnaceGeneratorHandler.deserializeNBT] tag={remainingBurnTime:200,fuelItem:{id:"minecraft:air",Count:0b,Damage:0s}}
[18:32:02] [main/INFO] [RadioTools]: [FurnaceGeneratorHandler.deserializeNBT] fuelItem=1xtile.air@0
[18:32:12] [main/INFO] [RadioTools]: [FurnaceGeneratorHandler.decreaseRemainingBurnTime] Finished burning
[18:32:12] [Server thread/INFO] [RadioTools]: [FurnaceGeneratorHandler.decreaseRemainingBurnTime] Finished burning
[18:32:12] [Server thread/INFO] [RadioTools]: [FurnaceGeneratorHandler.serializeNBT] this.fuelItem=1xtile.air@0
[18:32:12] [Server thread/INFO] [RadioTools]: [FurnaceGeneratorHandler.serializeNBT] tag={remainingBurnTime:0,fuelItem:{id:"minecraft:air",Count:1b,Damage:0s}}
[18:32:12] [main/INFO] [RadioTools]: [FurnaceGeneratorHandler.deserializeNBT] tag={remainingBurnTime:0,fuelItem:{id:"minecraft:air",Count:1b,Damage:0s}}
[18:32:12] [main/INFO] [RadioTools]: [FurnaceGeneratorHandler.deserializeNBT] fuelItem=1xtile.air@0

 

 

Anybody with good eyes?

 

Linda

 

[jabelar]

So I can tell by your coding style that you are a competent programmer. So I suggest that you just need to learn a bit more about debugging tools. In your IDE (Eclipse or whatever you're using) you should have ability to run in a debug mode where you can watch field values and set breakpoints and such. With that it should quickly become obvious why any field isn't getting the value you expect.

 

Since I like debugging issues during actual gameplay I find the debug mode can be a bit limiting for some situations (like you can't breakpoint every rendering frame) so I like to add my own console or logger statements. By putting them in judicious points in the code (usually in each method call to confirm that the method was called and the value of the parameters passed in) and at each logical branch in the code you can very quickly figure out what is going wrong.

 

You're partly there as you are outputting some values to the console. So why not go further and trace the entire (relevant) logic of your code.

 

 

[lyn mimistrobell]

I did add more debugging and found the issue is with ItemStack.deserializeNBT which doesn't handle the NBT (created with ItemStack.serializeNBT) properly (created a separate topic for that).

 

I use Eclipse Neon  2 and I know how to set breakpoints (unfortunately, they didn't help for this problem) - I didn't think use the property as watchpoint but I'll do that next time. Thanks.