Performance improvements when crafting batches

[richardhendricks]

2.0.8.0

When using shift-click to craft a whole stack, a massive lag spike hits. This includes vanilla crafting tables, TiCon crafting stations, and Forestry worktables. Has been an ongoing issue for a really long time (https://www.reddit.com/r/feedthebeast/comments/9gdy35/can_we_fix_the_dreaded_crafting_lag_in_minecraft/)

FastCraft Sampler on a single item craft in a vanilla table https://cdn.discordapp.com/attachments/401118216228831252/653456297995534357/unknown.png

FastCraft Sampler on a 64 item craft in a vanilla table https://cdn.discordapp.com/attachments/401118216228831252/653456409266225155/unknown.png

FastCraft sampler on a 64 item craft in a Forestry Worktable https://cdn.discordapp.com/attachments/401118216228831252/653463719304495139/unknown.png

Looking in Forge sourcecode, it looks like the shift key causes this loop GuiContainer::mouseMovedUpOrDown

        if (this.field_146993_M && slot != null && p_146286_3_ == 0 && this.inventorySlots.func_94530_a((ItemStack)null, slot))
        {
            if (isShiftKeyDown())
            {
                if (slot != null && slot.inventory != null && this.field_146994_N != null)
                {
                    iterator = this.inventorySlots.inventorySlots.iterator();

                    while (iterator.hasNext())
                    {
                        slot1 = (Slot)iterator.next();

                        if (slot1 != null && slot1.canTakeStack(this.mc.thePlayer) && slot1.getHasStack() && slot1.inventory == slot.inventory && Container.func_94527_a(slot1, this.field_146994_N, true))
                        {
                            this.handleMouseClick(slot1, slot1.slotNumber, p_146286_3_, 1);
                        }
                    }
                }
            }
            else
            {
                this.handleMouseClick(slot, j1, p_146286_3_, 6);
            }

            this.field_146993_M = false;
            this.field_146997_J = 0L;
        }

The while loop with isShiftKeyDown causes canTakeStack/getHasStack iterations on the container. These will cause continuous recipe lookups on the contents of any crafting grid.

Confirmed in 2.0.7.5 as well, causes server to lock hard for up to 8s with a 3x3 craft of 64 items.

The forestry table is slightly better than the ticon table or vanilla crafting table, probably because of this? TileWorktable::OnCraftingStart

        // craft recipe should exactly match ingredients here, so no oreDict or tool matching
        ItemStack[] removed = InventoryUtil.removeSets(this, 1, recipeItems, player, false, false, false);
        if (removed == null) {
            return false;
        }

(just looking at forestry worktable) One option would be to throttle the number of items that can be crafted per click, by returning false from canTakeStack in the ICrafterWorktable interface if too many items are taken in 1 tick, and/or the tick time is too long. Easiest solution, but makes it a bit painful to use the table to craft lots of items at once.

More complex idea would be to have the mod detect the shift key is down, and do some sort of optimizations, maybe retain the recipe or something so that it doesn't have to search it over and over.

[richardhendricks]

check if this is a new tick, if it is clear the cache. canTakeStack is called multiple times in the code in direct and indirect ways.

if (slot1 != null && slot1.canTakeStack(this.mc.thePlayer) && slot1.getHasStack() && slot1.inventory == slot.inventory && Container.func_94527_a(slot1, this.field_146994_N, true))

1 direct call here

Then in getHasStack

    public boolean getHasStack() {
        return getStack() != null && crafter.canTakeStack(getSlotIndex());
    }

Then two more times in func_94527_a()

    public static boolean func_94527_a(Slot p_94527_0_, ItemStack p_94527_1_, boolean p_94527_2_)
    {
        boolean flag1 = p_94527_0_ == null || !p_94527_0_.getHasStack();

        if (p_94527_0_ != null && p_94527_0_.getHasStack() && p_94527_1_ != null && p_94527_1_.isItemEqual(p_94527_0_.getStack()) && ItemStack.areItemStackTagsEqual(p_94527_0_.getStack(), p_94527_1_))
        {
            int i = p_94527_2_ ? 0 : p_94527_1_.stackSize;
            flag1 |= p_94527_0_.getStack().stackSize + i <= p_94527_1_.getMaxStackSize();
        }

        return flag1;
    }

So anything we can do to optimize that getHasStack call would be a great improvement.

[richardhendricks]

Bigbass says this hasn't been an issue with him on 2.0.7.5, not sure as to why.

[richardhendricks]

totalWorldTime is available to get the current tick, can be used to implement something.

[Dream-Master]

@richardhendricks is there anything we can do? add code?

[richardhendricks]

I am investigating.

This mod https://www.curseforge.com/minecraft/mc-mods/fastworkbench (for newer minecraft) implements what looks like the best option (caching the recipe and re-using it vs rescanning) but we might be able to do something very simple so that it only rescans the recipe list 1x per craft instead of 4x.

[richardhendricks]

https://dzone.com/articles/java-collection-performance I wonder if some performance optimizations are possible with the oredict.

[richardhendricks]

https://www.minecraftforge.net/forum/topic/78645-1710-shift-crafting-lag/

[richardhendricks]

[repo-alt]

Lol at the forge helpful attitude.

[richardhendricks]

I don't really blame them, but whatevs. We've probably got enough in house expertise, and probably the most recent 1.7.10 experts anyways.

[richardhendricks]

Well I did just back LexManos' patreon, I;ll give that a ping haha

[richardhendricks]

• Check the current tick against the saved tick number, and if they are different, perform usual recipe scan behavior. Update saved tick number + save system time => this will detect if the slot is receiving a lot of requests in a single tick

• If the current tick is the same, compare current system time against saved system time, if the difference is greater than X (probably 1s?), return false to break out of loop => this will rate-limit the shift-crafting so it doesn't hardlock the server for more than the time allowed.

• Check if the slot has been modified, if it has, perform usual recipe scan behavior. Mark slot unmodified => this will detect if the slot has been changed, or if code is just asking that it could be changed.

• If the slot is modified/item successfully extracted, mark the slot modified. => Tells canTakeStack it has to rescan recipes.

[richardhendricks]

Okay, first part is implemented. If a recipe is loop-crafting for longer than a configurable amount of time, it breaks out. Working on isDirty step next.

[richardhendricks]

Example of crafting stopping after 750ms, only crafted 13 woven cloth

[richardhendricks]

Adding the isDirty check didn't seem to have much effect. Need to see if there is another solution here.

[Bluebine]

The crafting stopping after a certain time sounds even more annoying than the game freezing. If you do implement that, please make it only on by default on the servers, I think most SP players would rather freeze for a bit versus having to spamclick to craft stuff.

[StoneLegion]

Thanks for looking into this. Sadly one the worst things that happen in MC when you have too many items to go through the array. Hopefully we can figure out how to cache the stack rather then 64 look ups. That being said once the time comes I'm willing to take dirty fixes if it means less suffering for servers.

But I agree with Bluebine I don't see it needed for SP users unless it's a cache fix because if they pause or not it does not effect anyone but themselves.

[richardhendricks]

RecipeUtil.java

    public static InventoryCraftingForestry getCraftRecipe(ItemStack[] recipeItems, ItemStack[] availableItems, World world, ItemStack recipeOutput) {
        // Need at least one matched set
        if (ItemStackUtil.containsSets(recipeItems, availableItems, true, true) == 0) {
            return null;
        }
        long currentTime = System.nanoTime();

        // Check that it doesn't make a different recipe.
        // For example:
        // Wood Logs are all ore dictionary equivalent with each other,
        // but an Oak Log shouldn't be able to make Ebony Wood Planks
        // because it makes Oak Wood Planks using the same recipe.
        // Strategy:
        // Create a fake crafting inventory using items we have in availableItems
        // in place of the ones in the saved crafting inventory.
        // Check that the recipe it makes is the same as the currentRecipe.
        InventoryCraftingForestry crafting = new InventoryCraftingForestry();
        ItemStack[] stockCopy = ItemStackUtil.condenseStacks(availableItems);

        for (int slot = 0; slot < recipeItems.length; slot++) {
            ItemStack recipeStack = recipeItems[slot];
            if (recipeStack == null) {
                continue;
            }

            // Use crafting equivalent (not oredict) items first
            for (ItemStack stockStack : stockCopy) {
                if (stockStack.stackSize > 0 && ItemStackUtil.isCraftingEquivalent(recipeStack, stockStack, false, false)) {
                    ItemStack stack = ItemStackUtil.createSplitStack(stockStack, 1);
                    stockStack.stackSize--;
                    crafting.setInventorySlotContents(slot, stack);
                    break;
                }
            }

            // Use oredict items if crafting equivalent items aren't available
            if (crafting.getStackInSlot(slot) == null) {
                for (ItemStack stockStack : stockCopy) {
                    if (stockStack.stackSize > 0 && ItemStackUtil.isCraftingEquivalent(recipeStack, stockStack, true, true)) {
                        ItemStack stack = ItemStackUtil.createSplitStack(stockStack, 1);
                        stockStack.stackSize--;
                        crafting.setInventorySlotContents(slot, stack);
                        break;
                    }
                }
            }
        }
        System.out.println("after oredicting: " + (System.nanoTime() - currentTime)/1000 );

        List<ItemStack> outputs = findMatchingRecipes(crafting, world);

        System.out.println("after findMatchingRecipes: " + (System.nanoTime() - currentTime)/1000 );
        if (!ItemStackUtil.containsItemStack(outputs, recipeOutput)) {
            return null;
        }

        System.out.println("after containsItemStack: " + (System.nanoTime() - currentTime)/1000 );
        return crafting;
    }

[00:33:52] [Client thread/INFO] [STDOUT]: [forestry.factory.tiles.TileWorktable:canCraftCurrentRecipe:146]: cleanCount 26 totalCount 52
[00:33:52] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 4
[00:33:52] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 13313
[00:33:52] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 13495
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.factory.tiles.TileWorktable:canCraftCurrentRecipe:146]: cleanCount 0 totalCount 1
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 3
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 10838
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 10973
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 3
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 10370
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 10544
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 4
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 10514
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 10683
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 3
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 10614
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 10805
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 3
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 10492
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 10666
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 3
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 10415
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 10575
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 3
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 10609
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 10822
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 3
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 10942
[00:33:54] [Client thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 11121
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.factory.tiles.TileWorktable:canCraftCurrentRecipe:146]: cleanCount 25 totalCount 51
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 5
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 12844
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 12995
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 5
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 11635
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 11783
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 3
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 13977
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 14125
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 4
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 10948
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 11082
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 3
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 12596
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 12773
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 5
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 13511
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 13652
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 4
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 10887
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 11105
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:144]: after oredicting: 7
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:148]: after findMatchingRecipes: 12185
[00:33:54] [Server thread/INFO] [STDOUT]: [forestry.core.recipes.RecipeUtil:getCraftRecipe:153]: after containsItemStack: 12316

Looks like quite a bit of time is spent in this function, and for some reason it is called multiple times per single item. Above log is from shift-clicking with enough resources to craft 4 items. Looks like 16 calls to it. Times are given in microseconds. So each item is spending approximately 48ms of time here.

[richardhendricks]

Most of that time is spent in findMatchingRecipes. Based on what I can deduce, what this function does is

For each recipeitem
   For each availableitem
     If the available item is a match 
        add it to potential crafting

Once the possible items for the craft are confirmed, it determines from Forge what that recipe would make. (this is the stage that takes the most time)

It then checks that the output of this recipe matches the requested recipe output.

[richardhendricks]

everything is really really fast except for the "hey forge, what does this recipe make" part.

[richardhendricks]

    public static List<ItemStack> findMatchingRecipes(InventoryCrafting inventory, World world) {
        ItemStack repairRecipe = findRepairRecipe(inventory);
        if (repairRecipe != null) {
            return Collections.singletonList(repairRecipe);
        }

        List<ItemStack> matchingRecipes = new ArrayList<>();

        for (Object recipe : CraftingManager.getInstance().getRecipeList()) {
            IRecipe irecipe = (IRecipe) recipe;

            if (irecipe.matches(inventory, world)) {
                ItemStack result = irecipe.getCraftingResult(inventory);
                if (!ItemStackUtil.containsItemStack(matchingRecipes, result)) {
                    matchingRecipes.add(result);
                }
            }
        }

        return matchingRecipes;
    }

Should be able to add an ezpz cache here to at least match on already-found recipes. Will try tomorrow.

[richardhendricks]

Hmm. I don't know if it is a great idea, but one possible option instead of keeping a local recipe cache is manipulating the CraftingManager recipe list. It's not something you can do directly in this iterator, but maybe after the search is done, delete the found recipes from the RecipeList and re-add them to the front using the Queue operations.

We would have to break out of the for loop once we find a recipe - I am not sure why the loop traverses the whole recipe list, there should be only 1 output from a matching set of inputs (obviously there can be multiple input sets to make 1 output, but this is looking at the inputs).

Pro: Moving recipes would speed up first-found searches for everyone Con: Messing with the RecipeList sounds dangerous. This might also be a pro, lol.

Alternative: We would create a cacheRecipeList (I am thinking as a separate API mod so other mods can use it) that is checked first. This cacheRecipeList would implement the MRU mechanism above - if an item is found, move it to the front of the list. If an item is not found in the cache, then the search above is performed. As recipes are found, they are added to the front of the list. It would probably be a good idea to keep an eye on the size and limit it to a reasonable amount - maybe a few hundred recipes max - to keep performance high. The cache would not persist on server restarts and would be rebuilt over time as the recipes are used in the machines.

Todo:

• How big is the recipe list, anyways?
• Is it possible to modify the recipe list?
• @mitchej123 @draknyte1 any ideas why the loop would not break on the first recipe found? I would not expect the same inputs to have more than one type of outputs, unless there are buggy recipes.
• I think the crafting timeout should probably be inside Forge to force it for all, or at a minimum in the crafting table.

Potential "crafting table" blocks Crafting table /workbench on servers Ticon Crafting station Forestry Worktable Thaumcraft Worktable Autocrafter? World Interaction Node? SFM? AE2? Crafting wand focus Arcane autocrafter biblio craft has a bunch there is a crafting cart by railcraft Steves carts as well this may be a good idea for sfm as well Project red atuo crafting bench open computers can do crafting requrests as well Natura backpacks iirr gt crafting cover Avatria 9x9

[richardhendricks]

You two are silly. GT_ItemStack And the hashing function within.. perfectly used instead of ItemStacks for Map Keys, etc. @bartimaeusnek @moronwmachinegun

[richardhendricks]

OK, so I tried just implementing the first option, deleting the recipe when found and moving it to the front of the recipe list, and it works. Right now this code is only implemented for the Forestry Worktable.

Doing recipe at normal Crafting Table before speedup - 5.8s

Doing recipe at Forestry Worktable - 81ms

Doing recipe back at normal Crafting Table after speedup - 95ms

95ms is still a big hit, but it's a hell of a lot less than 6s. I want to look at the Forestry code some more and try to understand why the code is called multiple times through the loop per item crafted.

[richardhendricks]

Hmm, well all is not good. Seems to have a couple of issues. These issues might not be related to my code though, will need to test on an unmodified Forestry

• [x] Steel dust piles don't show small dusts recipe, only tiny dusts
• [x] Steel to tiny dusts, back to steel, ended up missing 1 tiny dust.
• [ ] Weird UI behavior when insufficient items to make. Filled up all slots with target item, and then removed them all? (crashy)
• [ ] Crashed on crafting sometimes with dusts with a stack overflow exception error. Stack shows looping between ContainerForestry.java::82 and Container.func_75133_b, line 365 and container.func_75144_a line 199
• [ ] Similar issues with chisel + brownstone shapeless recipe.

[richardhendricks]

Second way is to try just saving the last-found recipe locally in the RecipeUtil class. It will still speed up shift-click crafting on the worktable but not mess with the recipemap, and won't help with crafting table.

[richardhendricks]

Caused by: java.lang.StackOverflowError
    at forestry.core.utils.ItemStackUtil.condenseStacks(ItemStackUtil.java:115) ~[ItemStackUtil.class:?]
    at forestry.core.utils.ItemStackUtil.containsSets(ItemStackUtil.java:153) ~[ItemStackUtil.class:?]
    at forestry.core.utils.ItemStackUtil.containsSets(ItemStackUtil.java:144) ~[ItemStackUtil.class:?]
    at forestry.core.recipes.RecipeUtil.getCraftRecipe(RecipeUtil.java:99) ~[RecipeUtil.class:?]
    at forestry.factory.tiles.TileWorktable.onCraftingStart(TileWorktable.java:175) ~[TileWorktable.class:?]
    at forestry.core.gui.slots.SlotCrafter.func_82870_a(SlotCrafter.java:59) ~[SlotCrafter.class:?]
    at forestry.core.utils.SlotUtil.transferStackInSlot(SlotUtil.java:94) ~[SlotUtil.class:?]
    at forestry.core.gui.ContainerForestry.func_82846_b(ContainerForestry.java:91) ~[ContainerForestry.class:?]
    at net.minecraft.inventory.Container.func_75144_a(SourceFile:193) ~[zs.class:?]
    at forestry.core.gui.ContainerForestry.func_75144_a(ContainerForestry.java:82) ~[ContainerForestry.class:?]
    at net.minecraft.inventory.Container.func_75133_b(SourceFile:365) ~[zs.class:?]
    at net.minecraft.inventory.Container.func_75144_a(SourceFile:199) ~[zs.class:?]
    at forestry.core.gui.ContainerForestry.func_75144_a(ContainerForestry.java:82) ~[ContainerForestry.class:?]
    at net.minecraft.inventory.Container.func_75133_b(SourceFile:365) ~[zs.class:?]
    at net.minecraft.inventory.Container.func_75144_a(SourceFile:199) ~[zs.class:?]
    at forestry.core.gui.ContainerForestry.func_75144_a(ContainerForestry.java:82) ~[ContainerForestry.class:?]
    at net.minecraft.inventory.Container.func_75133_b(SourceFile:365) ~[zs.class:?]
    at net.minecraft.inventory.Container.func_75144_a(SourceFile:199) ~[zs.class:?]
    at forestry.core.gui.ContainerForestry.func_75144_a(ContainerForestry.java:82) ~[ContainerForestry.class:?]
    at net.minecraft.inventory.Container.func_75133_b(SourceFile:365) ~[zs.class:?]
    at net.minecraft.inventory.Container.func_75144_a(SourceFile:199) ~[zs.class:?]
    at forestry.core.gui.ContainerForestry.func_75144_a(ContainerForestry.java:82) ~[ContainerForestry.class:?]
    at net.minecraft.inventory.Container.func_75133_b(SourceFile:365) ~[zs.class:?]
    at net.minecraft.inventory.Container.func_75144_a(SourceFile:199) ~[zs.class:?]
    at forestry.core.gui.ContainerForestry.func_75144_a(ContainerForestry.java:82) ~[ContainerForestry.class:?]
    at net.minecraft.inventory.Container.func_75133_b(SourceFile:365) ~[zs.class:?]

[richardhendricks]

OK, early leaving isn't going to work. Rolling back to the normal version, it does work correctly with small and tiny stacks as output options. Will need to think about how to solve this. I think we'll have to use the alternate option of a local cache, which is a bummer because it would help accelerate other machines that do exit early. Or maybe just do both? Hmmm, grinding sounds

The "losing a tiny dust" issue is present in the normal release, so that's not a new bug LOL.

Tinker chisel and brownstone blocks work goofy on the standard Forestry release too.

[StoneLegion]

Good luck on this mate. Don't burn yourself out. It's something plagued a lot of people and versions of modded minecraft and honestly still does. It's only starting become a point where devs are waking up and fixing it in their mods.

[richardhendricks]

Thanks for the encouragement, I do think it is a worthwhile thing to look at. The worktable does not use the base container crafting search, so it pretty much needs its own custom changes anyways.

I looked, and on later versions of Minecraft Forge does implement basically the hashmap backed with lists like you and I were talking about @bartimaeusnek . You have to do both because you cannot guarantee recipes won't have the same hash. But it does make recipe lookup much faster when using vanilla searches. If a mod does its own search, it needs to be smart about it to not hog all the resources.

I think I understand why the search happens twice. I suspect it is because the slot is updating its ghost output after each single craft during the shift-craft. I will look at that after I implement the updated caching/recipe mapping.

I think I will do both for the worktable. It will make the worktable much faster to have the recipe cache local, since it really does have to search the whole recipelist. But moving the located recipes to the front of the recipelist will help for any incidental crafting like with /workbench or other random crafting tables.

I might implement a throttling so that it will only move recipe items if they were found outside the first 500 in the recipelist. This might not be necessary if the worktable keeps a local cache, since it won't try to move items a second time.

I need to look at how TiCon does its crafting station, and how AE2 does its crafting. If both use the normal worktable crafting, we'll look at doing a forge patch. But I think adding a tooltip note "Do the craft first on a worktable or insert other craft interface we can control, like GT cover before using in AE2 to improve performance" might help at least for those willing to follow the instructions.

And again, we can implement moving recipes to the front of the list with MineTweaker too. We'll have to think about which ones need it.

[repo-alt]

AE2 uses net.minecraft.inventory.InventoryCrafting and does not cache the recipe (as far as I can see) cf. appeng.container.slot.SlotCraftingTerm.doClick

[richardhendricks]

@repo-alt Does it rescan the recipe every time it attempts to craft? Does it limit somehow how many it does per tick? That's really good news, we could either patch the function in Forge or add a cache in AE.

[repo-alt]

Does no time limit as far as I can see. Looks up the recipe every time, like this:

    public static IRecipe findMatchingRecipe( final InventoryCrafting inventoryCrafting, final World par2World )
    {
        final CraftingManager cm = CraftingManager.getInstance();
        final List<IRecipe> rl = cm.getRecipeList();

        for( final IRecipe r : rl )
        {
            if( r.matches( inventoryCrafting, par2World ) )
            {
                return r;
            }
        }

        return null;
    }

[richardhendricks]

That logic might in higher levels than down here.

This is good, it means it returns immediately on the first match. We could just edit the recipemap here and it should accelerate the followup searches in a multicraft.

[richardhendricks]

If you have access, a simple test can tell you if this idea will make a difference.

Cobble to cobble stairs is very early in the recipemap since it is an unchanged MC recipe.

Cotton + string => woven cloth is a MT recipe, which dumbly places them at the end of the recipemap, and will be a slow search.

Do a craft of a few stacks of each and see what your tick overhead is, and how long they take to complete.

[repo-alt]

Well, AE does it's own ticking indeed, but once it started crafting, there is no control intercept, unless it uses other thread for that which I doubt.

[richardhendricks]

So they are equally fast?

[repo-alt]

Test, you mean with fastcraft sampler? Never used it, I will try.

[richardhendricks]

Yeah that would work. Or you could just try it and get a feel for it. xu_tps will give you the TPS.

[repo-alt]

Well, I was not able to export samples, but tps drops significantly on crafting cotton (to 13) and does not drop at all at crafting stairs, so recipe searching does have quite an impact on performance.

[repo-alt]

Actually I'll insert a primitive recipe cache (LRU) and test it again.

[richardhendricks]

I'm at work right now, but when I get home I'll post my code.

[richardhendricks]

some tips

• Add the recipes to the cache at the front. In this situation since you stop on first match, putting them first is a benefit. On the Worktable it traverses the whole thing so it doesn't matter.
• You can ignore adding the recipe if the recipe is in the first ~500 entries in the recipe map. Add an index counter to your for loop so you can keep track of when you exit. For my code, I had to do a list since multiple matches could occur
• The cache must be a static class member, obviously.

[richardhendricks]

And it's MRU, I keep making the same mistake. :) Used to CPU caches where you talk about who you are kicking out, not which you are promoting to the front.

[repo-alt]

MRU, right (last/least confusion). I added the cache to the SlotCraftingTerm, not touching the recipe list itself.

[repo-alt]

Ok, MRU 1 line cache removed the TPS hit completely.

[richardhendricks]

It's such a dumb easy optimization I am amazeballs nobody else did it. Great job!

[repo-alt]

Apparently for 1.12 somebody did, but why it took so long to notice is unclear.

[richardhendricks]

With just a 1 slot cache, how well does it work if you have two or more crafting terminals running?

[repo-alt]

The manual crafting from the terminals happens within one tick apparently, so it does not matter if the cache will change at the next terminal. It really just matters for batches. Of course if you craft one item at one terminal, switch to another, craft one item there, then the cache won't help, but such use case looks a bit contrived.