Applied Energistics 2

Applied Energistics 2

156M Downloads

Incorrect crafting job progress bar (not consumed item)

RobbyLPHD opened this issue · 7 comments

commented

Describe the bug

As soon as there are reused items in an autocrafting recipe, the display goes above 100%. The remaining time display also disappears as soon as 100% is exceeded.
(Screenshot in Additional details.)

How to reproduce the bug

Use an item in a crafting recipe that is not consumed. The display now goes over 100% for a larger recipe, as the recovered item probably counts towards the total number of crafted items. (Noticed when crafting Mystical agricultur essence with master infusion cristal.)

Expected behavior

Normally 100% should not be exceeded.

Additional details

2023-11-11_23 51 46

Which minecraft version are you using?

1.20

On which mod loaders does it happen?

Forge

Crash log

No crash, just a display error

commented

Ok, finally got to a point where I can compile AE2 for 1.20.1 at least via commandline. I added a bunch of debug prints in the place where crafted items get imported back into the Crafting CPU (CraftingCPULogic.insert()), showing that for the recipe from my last post my suspicions were correct. First the main product (Prudentium Essence) is inserted, then the byproduct (Infusion Crystal with reduced durability) is inserted next. For each of them, job.timeTracker.decrementItems(amount); is called, amount being 1 every time. In total this means job.timeTracker.decrementItems(amount); is called 19 times with an amount of 1.

The initial value of job.timeTracker.getRemainingItemCount() was only 10 to begin with, which leads to a final value of -9 rather than 0 as one would expect for a normal crafting job. This is by the way consistent with the amount the bar exceeds the max width, i.e. it being twice the size it should be in my example. Interesting side note: -9 is the final value and not -10 as the last Infusion Crystal is not inserted into the Crafting CPU anymore as the last Prudentium Essence seems to terminate the crafting job now that all of them have come in.

Another detail I printed was the job.waitingFor.list, which seems to either have just one item in it (the Infusion Crystal) if the item being currently inserted is the Prudentium Essence or being empty if the Infusion Crystal is being inserted.

The question remains whether the crafting calcuation should yield an expected count of 20 items for the initial job.timeTracker.getRemainingItemCount() rather than just 10 or if the insertion should somehow only count the main product. Both would probably work but which one is the correct solution depends on the semantics of what the crafting calculation is supposed to do.

This is the complete trace:

[21:18:40] [AE Crafting Calculator/INFO] [AE2:S/]: Mithi83 marker ******************************************************************************************************************************
[21:18:40] [AE Crafting Calculator/INFO] [AE2:S/]: CraftingCalculation issued by ServerPlayer['mithi83'/19, l='ServerLevel[Test]', x=3.55, y=-60.00, z=9.80] requesting [10xmysticalagriculture:prudentium_essence] breakdown:
 - 10 succeeded (104 bytes) in 0 ms
 - final plan: 10 (104 bytes)
0 missing items
0 emitted items
2 used items 1xtranslation{key='item.mysticalagriculture.infusion_crystal', args=[]} 40xtranslation{key='item.mysticalagriculture.inferium_essence', args=[]}
[21:18:40] [Server thread/INFO] [AE2:S/]: main thread is now active
[21:18:53] [Server thread/INFO] [AE2:S/]: insert 1x Prudentium Essence remaining 9 waiting for 1
  1xInfusion Crystal
[21:18:53] [Server thread/INFO] [AE2:S/]: insert 1x Infusion Crystal remaining 8 waiting for 0
[21:18:54] [Server thread/INFO] [AE2:S/]: insert 1x Prudentium Essence remaining 7 waiting for 1
  1xInfusion Crystal
[21:18:54] [Server thread/INFO] [AE2:S/]: insert 1x Infusion Crystal remaining 6 waiting for 0
[21:18:54] [Server thread/INFO] [AE2:S/]: insert 1x Prudentium Essence remaining 5 waiting for 1
  1xInfusion Crystal
[21:18:54] [Server thread/INFO] [AE2:S/]: insert 1x Infusion Crystal remaining 4 waiting for 0
[21:18:55] [Server thread/INFO] [AE2:S/]: insert 1x Prudentium Essence remaining 3 waiting for 1
  1xInfusion Crystal
[21:18:55] [Server thread/INFO] [AE2:S/]: insert 1x Infusion Crystal remaining 2 waiting for 0
[21:18:55] [Server thread/INFO] [AE2:S/]: insert 1x Prudentium Essence remaining 1 waiting for 1
  1xInfusion Crystal
[21:18:55] [Server thread/INFO] [AE2:S/]: insert 1x Infusion Crystal remaining 0 waiting for 0
[21:18:56] [Server thread/INFO] [AE2:S/]: insert 1x Prudentium Essence remaining -1 waiting for 1
  1xInfusion Crystal
[21:18:56] [Server thread/INFO] [AE2:S/]: insert 1x Infusion Crystal remaining -2 waiting for 0
[21:18:57] [Server thread/INFO] [AE2:S/]: insert 1x Prudentium Essence remaining -3 waiting for 1
  1xInfusion Crystal
[21:18:57] [Server thread/INFO] [AE2:S/]: insert 1x Infusion Crystal remaining -4 waiting for 0
[21:18:57] [Server thread/INFO] [AE2:S/]: insert 1x Prudentium Essence remaining -5 waiting for 1
  1xInfusion Crystal
[21:18:57] [Server thread/INFO] [AE2:S/]: insert 1x Infusion Crystal remaining -6 waiting for 0
[21:18:58] [Server thread/INFO] [AE2:S/]: insert 1x Prudentium Essence remaining -7 waiting for 1
  1xInfusion Crystal
[21:18:58] [Server thread/INFO] [AE2:S/]: insert 1x Infusion Crystal remaining -8 waiting for 0
[21:18:58] [Server thread/INFO] [AE2:S/]: insert 1x Prudentium Essence remaining -9 waiting for 1
  1xInfusion Crystal
[21:19:01] [Server thread/INFO] [minecraft/IntegratedServer]: Saving and pausing game...
commented

Next round of debug printing: Crafting Calculation just looks at pattern outputs (ExecutingCraftingJob first constructor) whereas during execution of a job in CraftingCpuLogic.executeCrafting we take a look at the pattern outputs plus any remainders in the input slots that were not used up. This is hidden in the function CraftingCpuHelper.extractPatternInputs, as there are two places that call expectedOutputs.add(), one for the remaining items in the input slots and one for the pattern outputs.

The crafting calculation is used to set the inital job.timeTracker.getRemainingItemCount() to 10 initially as it ignores the remainder of the input length, thus creating the discrepancy. Looking at how much effort was spent on the details of CraftingCpuHelper.extractPatternInputs I'd tend to say that the correct fix would be to replicate those details in the ExecutingCraftingJob constructor.

The code in question was added or had a major rewrite in late 2021 by Technici4n for the feature "fluid autocrafting".

commented

Just as a proof of concept I modified the constructor of ExecutingCraftingJob to account for remaining items and the total number seems to be OK, as well as the bar length now staying within expected limits. For my test setup this code (I added the for for the inputs) works, but as I'm not familiar enough with that code someone else should take it from here:

        for (var entry : plan.patternTimes().entrySet()) {
            tasks.computeIfAbsent(entry.getKey(), p -> new TaskProgress()).value += entry.getValue();
            for (var input : entry.getKey().getInputs()) {
                if (input.getRemainingKey(input.getPossibleInputs()[0].what()) != null ) {
                    totalPending += entry.getValue();
                }
            }
            for (var output : entry.getKey().getOutputs()) {
                totalPending += output.amount() * entry.getValue();
            }
        }

Rationale: I try to replicate the logic of CraftingCpuHelper.extractPatternInputs here. As we however don't have a specific inventory at this point, I just guessed that input.getPossibleInputs()[0].what() would be a good starting point. This should probably be made more robust by someone who knows these data structures better. Also I'm not sure if we need another factor in there, rather than just the entry.getValue() since my test pattern will always return 1 Infusion Crystal.

commented

Another test case I had for a while now works with this fix too. In ATM9 I have a rather complex chain of patterns for producing tin rotors (from GregTech) which reused a lot of the tools (again with reducing durability on use). This showed the same symptoms of overly long progess bars.

commented

Some more insight and a reduced reproduction setup on 1.20.1 with Mystical Agriculture:

  • Prepare a crafting pattern with that takes 4 Inferium Essence and 1 Infusion Crystal, allow substitutions and place it in a pattern provider next to a single molecular assembler without upgrades. This produces 1 Prudentium Essence and reduces the Infusion Crystal use count by one (somewhat like durability I guess).
  • Prepare a disk with a stack of Inferium Essence and 1 Infusion Crystal
  • Prepare for crafting 10 Prudentium Essence and examine the Crafting plan.
  • Notice that only 1 Infusion Crystal (marked as available) is listed. 40 Inferium Essence is marked as available and 10 Prudentium Essence is marked as "to craft"
  • Start the Crafting plan and swiftly monitor the crafting status
  • Notice the progress bar exceed the max width towards the end.

What I imagine happening is that the crafting plan does not account for the returning Infusion Crystal that is reused in the next step with a reduced durability (as substitutions are allowed), however the code dealing with the items being inserted counts it each time (CraftingCpuLogic::insert -> ElapsedTimeTracker::decrementItems which is ultimately the basis for rendering the progress bar).
I have not yet figured out how a crafting plan is calculated in the first place. Somehow the algorithm must be clever enough to detect that the Infusion Crystal can be reused in the many iterations of the one recipe.
You could now tackle the problem from two sides: Either the crafting plan must account for items returning for reuse up front or the accounting of returning items must differentiate later on.

commented

This reminds me of this of this bug here: #7420

I think your observation that items that are used multiple times (like catalysts in chemistry) is the key point here. I would guess that during crafting the catalyst is counted each time a crafting step finished while the total number of expected crafting steps only counts it once. This would imply that the number of finished steps would be larger than the total number of expected steps at some point and the bar would exceed the maximum width.

There are two things that probably need be corrected here:

  • Clamp the maximum width during rendering of the progress bar to 100%. This fixes the visual bug of rendering a too large progress bar. However the bar will reach 100% long before the crafting request is finished.
  • Fix the discrepancy between expected step calculation and actual counting as described above. Then the problem of the previous change would be remedied.

For the second part I‘m not sure which of both behaviors is the correct one and which one needs adjustment.

commented

I have some slight problems to reproduce your problem, as I can't find any hints for compiling AE2 for forge.

The immediate problem with the bar which exceeds 100% probably comes from here (src\main\java\appeng\client\gui\widgets\CPUSelectionList.java):

                // Draw a bar at the bottom of the button to indicate job progress
                var progress = (int) (cpu.progress() * (buttonBg.getSrcWidth() - 1) / Math.max(1, cpu.totalItems()));

If cpu.progress() becomes larger than cpu.totalItems() you exceed the 100%. This should probably never happen, but if it does nothing prevents it from messing up the bar rendering. To fix that graphical problem of a bar extending too far to the right I suggest to change that to something like this:

                // Draw a bar at the bottom of the button to indicate job progress
                var totalItems = Math.max(1, cpu.totalItems());
                var progress = (int) (Math.min(cpu.progress(), totalItems) * (buttonBg.getSrcWidth() - 1) / totalItems);

This is untested code however, since I don't have a testbed with Mystical Agriculture.

This however just masks the graphical bug. The main problem is that cpu.progress() should probably never become larger than cpu.totalItems(). The proper solution for the problem would in my opinion require a dev to resolve the discrepancy between counting the actual crafting steps and the a priori calculated steps that treat reused items differently, counting the every time vs counting them only once.