Expose crafting job progress and measured recipe durations

src/main/java/org/cyclops/integratedcrafting/GeneralConfig.java

@@ -35,6 +35,12 @@ public class GeneralConfig extends DummyConfig {
     @ConfigurableProperty(category = "general", comment = "The base energy usage for the attuned crafting interface per crafting job being processed.", minimalValue = 0, configLocation = ModConfig.Type.SERVER)
     public static int interfaceCraftingAttunedBaseConsumption = 10;
 
+    @ConfigurableProperty(category = "machine", comment = "The maximum number of recipes that a crafting interface remembers crafting durations for, which are used to estimate the duration of crafting jobs. Set to 0 to disable recipe-specific estimations.", minimalValue = 0, isCommandable = true, configLocation = ModConfig.Type.SERVER)
+    public static int craftingInterfaceRecipeDurationEntries = 32;
+
+    @ConfigurableProperty(category = "machine", comment = "The number of ticks after which a measured crafting duration is forgotten, so that estimations follow changes to the network. Set to 0 to never forget them.", minimalValue = 0, isCommandable = true, configLocation = ModConfig.Type.SERVER)
+    public static int craftingInterfaceRecipeDurationMaxAge = 24000;
+
     @ConfigurableProperty(category = "machine", comment = "Enabling this option will log all recipe validation failures in crafting interfaces into the server logs", isCommandable = true, configLocation = ModConfig.Type.SERVER)
     public static boolean logRecipeValidationFailures = true;
 

src/main/java/org/cyclops/integratedcrafting/api/crafting/CraftingJob.java

@@ -35,6 +35,7 @@ public class CraftingJob {
     private final IntList dependencyCraftingJobs;
     private final IntList dependentCraftingJobs;
     private int amount;
+    private int amountTotal;
     private IMixedIngredients ingredientsStorage; // Total to extract from storage (simulated and immutable)
     private IMixedIngredients ingredientsStorageBuffer; // The actual ingredients from storage, which are consumed over time.
     private Map<IngredientComponent<?, ?>, MissingIngredients<?, ?>> lastMissingIngredients;
@@ -49,6 +50,7 @@ public CraftingJob(int id, int channel, IRecipeDefinition recipe, int amount, IM
         this.channel = channel;
         this.recipe = recipe;
         this.amount = amount;
+        this.amountTotal = amount;
         this.ingredientsStorage = ingredientsStorage;
         this.ingredientsStorageBuffer = new MixedIngredients(Maps.newIdentityHashMap());
         this.lastMissingIngredients = Maps.newIdentityHashMap();
@@ -86,6 +88,18 @@ public void setAmount(int amount) {
         this.amount = amount;
     }
 
+    /**
+     * @return The amount this job started with, including the amount that was crafted already.
+     *         Contrary to {@link #getAmount()}, this value is not decremented while crafting.
+     */
+    public int getAmountTotal() {
+        return amountTotal;
+    }
+
+    public void setAmountTotal(int amountTotal) {
+        this.amountTotal = amountTotal;
+    }
+
     public void addDependency(CraftingJob dependency) {
         dependencyCraftingJobs.add(dependency.getId());
         dependency.dependentCraftingJobs.add(this.getId());
@@ -239,6 +253,7 @@ public static CompoundTag serialize(HolderLookup.Provider lookupProvider, Crafti
         tag.put("dependencies", new IntArrayTag(craftingJob.getDependencyCraftingJobs()));
         tag.put("dependents", new IntArrayTag(craftingJob.getDependentCraftingJobs()));
         tag.putInt("amount", craftingJob.amount);
+        tag.putInt("amountTotal", craftingJob.amountTotal);
         tag.put("ingredientsStorage", IMixedIngredients.serialize(lookupProvider, craftingJob.ingredientsStorage));
         tag.put("ingredientsStorageBuffer", IMixedIngredients.serialize(lookupProvider, craftingJob.ingredientsStorageBuffer));
         tag.put("lastMissingIngredients", MissingIngredients.serialize(lookupProvider, craftingJob.lastMissingIngredients));
@@ -298,6 +313,8 @@ public static CraftingJob deserialize(HolderLookup.Provider lookupProvider, Comp
         Map<IngredientComponent<?, ?>, MissingIngredients<?, ?>> lastMissingIngredients = MissingIngredients
                 .deserialize(lookupProvider, tag.getCompound("lastMissingIngredients"));
         craftingJob.setLastMissingIngredients(lastMissingIngredients);
+        craftingJob.setAmountTotal(tag.contains("amountTotal", Tag.TAG_INT)
+                ? tag.getInt("amountTotal") : amount); // TODO: rm backwards-compat in next major
         craftingJob.setStartTick(tag.getLong("startTick"));
         craftingJob.setInvalidInputs(tag.getBoolean("invalidInputs"));
         if (tag.contains("initiatorUuid", Tag.TAG_STRING)) {
@@ -333,12 +350,14 @@ public CraftingJob clone(CraftingHelpers.IIdentifierGenerator identifierGenerato
         if (!this.getIngredientsStorageBuffer().isEmpty()) {
             throw new IllegalStateException("Cloning a job with an ingredient buffer is illegal");
         }
-        return new CraftingJob(
+        CraftingJob clone = new CraftingJob(
                 identifierGenerator.getNext(),
                 getChannel(),
                 getRecipe(),
                 getAmount(),
                 getIngredientsStorage()
         );
+        clone.setAmountTotal(getAmountTotal());
+        return clone;
     }
 }

src/main/java/org/cyclops/integratedcrafting/api/crafting/CraftingJobDependencyGraph.java

@@ -221,6 +221,7 @@ public void importDependencies(CraftingJobDependencyGraph craftingJobsGraph) {
      */
     public void mergeCraftingJobs(CraftingJob target, CraftingJob mergee, boolean markMergeeAsFinished) {
         target.setAmount(target.getAmount() + mergee.getAmount());
+        target.setAmountTotal(target.getAmountTotal() + mergee.getAmountTotal());
         target.setIngredientsStorage(CraftingHelpers.mergeMixedIngredients(
                 target.getIngredientsStorage(), mergee.getIngredientsStorage()));
 

src/main/java/org/cyclops/integratedcrafting/api/crafting/ICraftingInterface.java

@@ -77,6 +77,27 @@ public interface ICraftingInterface {
      */
     public void cancelCraftingJob(int channel, int craftingJobId);
 
+    /**
+     * @param craftingJobId A crafting job id.
+     * @return The tick at which the oldest running crafting operation of the given job was started,
+     *         or -1 if no operation is running, or if this is unknown.
+     */
+    public default long getCraftingJobEntryStartTick(int craftingJobId) {
+        return -1;
+    }
+
+    /**
+     * @param recipe A recipe.
+     * @return The estimated duration in ticks of a single crafting operation of the given recipe,
+     *         based on the operations that were performed by this interface before, or -1 if unknown.
+     *         This may fall back to the average duration over all recipes of this interface,
+     *         as recipe-specific durations are only remembered for a limited number of recipes,
+     *         and are forgotten once they become outdated.
+     */
+    public default long getEstimatedRecipeDuration(IRecipeDefinition recipe) {
+        return -1;
+    }
+
     /**
      * @return The prioritized position of this interface.
      */

src/main/java/org/cyclops/integratedcrafting/api/network/ICraftingNetwork.java

@@ -163,4 +163,14 @@ public <T, M> Iterator<CraftingJob> getCraftingJobs(int channel, IngredientCompo
      */
     public long getRunningTicks(CraftingJob craftingJob);
 
+    /**
+     * @param channel The channel.
+     * @param recipe A recipe.
+     * @return The estimated duration in ticks of a single crafting operation of the given recipe,
+     *         based on the operations that the crafting interfaces performed before, or -1 if unknown.
+     */
+    public default long getEstimatedRecipeDuration(int channel, IRecipeDefinition recipe) {
+        return -1;
+    }
+
 }

src/main/java/org/cyclops/integratedcrafting/core/CraftingHelpers.java

@@ -5,6 +5,7 @@
 import com.google.common.collect.Maps;
 import com.google.common.collect.Sets;
 import net.minecraft.core.Direction;
+import net.neoforged.neoforge.server.ServerLifecycleHooks;
 import net.minecraft.world.level.block.Block;
 import net.minecraft.world.level.block.entity.BlockEntity;
 import org.apache.commons.lang3.tuple.Pair;
@@ -1729,6 +1730,15 @@ public static boolean insertCrafting(Function<IngredientComponent<?, ?>, PartPos
         return ok;
     }
 
+    /**
+     * @return The current game tick of the server.
+     */
+    public static long getCurrentTick() {
+        // Fully qualified, as this class already imports org.apache.logging.log4j.Level
+        return ServerLifecycleHooks.getCurrentServer()
+                .getLevel(net.minecraft.world.level.Level.OVERWORLD).getGameTime();
+    }
+
     /**
      * Split the given crafting job amount into new jobs with a given split factor.
      * @param craftingJob A crafting job to split.
@@ -1758,6 +1768,7 @@ public static List<CraftingJob> splitCraftingJobs(CraftingJob craftingJob, int s
                 modulus--;
             }
             clonedJob.setAmount(newAmount);
+            clonedJob.setAmountTotal(newAmount);
         }
 
         // Collect dependency links

src/main/java/org/cyclops/integratedcrafting/core/CraftingJobHandler.java

@@ -6,6 +6,8 @@
 import it.unimi.dsi.fastutil.ints.Int2IntOpenHashMap;
 import it.unimi.dsi.fastutil.ints.Int2ObjectMap;
 import it.unimi.dsi.fastutil.ints.Int2ObjectOpenHashMap;
+import it.unimi.dsi.fastutil.longs.LongArrayList;
+import it.unimi.dsi.fastutil.longs.LongList;
 import it.unimi.dsi.fastutil.objects.Object2IntMap;
 import it.unimi.dsi.fastutil.objects.Object2IntOpenHashMap;
 import net.minecraft.core.Direction;
@@ -65,6 +67,8 @@ public class CraftingJobHandler {
     private final Int2ObjectMap<CraftingJob> finishedCraftingJobs;
     private final Map<IngredientComponent<?, ?>, Direction> ingredientComponentTargetOverrides;
     private final Int2IntMap nonBlockingJobsRunningAmount;
+    private final Int2ObjectMap<LongList> processingCraftingJobsStartTicks;
+    private RecipeDurationStatistics recipeDurationStatistics;
 
     public CraftingJobHandler(int maxProcessingJobs, boolean blockingJobsMode,
                               Collection<ICraftingProcessOverride> craftingProcessOverrides,
@@ -85,6 +89,7 @@ public CraftingJobHandler(int maxProcessingJobs, boolean blockingJobsMode,
         this.finishedCraftingJobs = new Int2ObjectOpenHashMap<>();
         this.ingredientComponentTargetOverrides = Maps.newIdentityHashMap();
         this.nonBlockingJobsRunningAmount = new Int2IntOpenHashMap();
+        this.processingCraftingJobsStartTicks = new Int2ObjectOpenHashMap<>();
     }
 
     public void writeToNBT(HolderLookup.Provider lookupProvider, CompoundTag tag) {
@@ -120,6 +125,12 @@ public void writeToNBT(HolderLookup.Provider lookupProvider, CompoundTag tag) {
                 pendingEntries.add(pendingIngredientInstances);
             }
             entriesTag.put("pendingIngredientInstanceEntries", pendingEntries);
+
+            LongList startTicks = this.processingCraftingJobsStartTicks.get(processingCraftingJob.getId());
+            if (startTicks != null) {
+                entriesTag.putLongArray("pendingIngredientInstanceEntryStartTicks", startTicks.toLongArray());
+            }
+
             processingCraftingJobs.add(entriesTag);
         }
         tag.put("processingCraftingJobs", processingCraftingJobs);
@@ -147,6 +158,10 @@ public void writeToNBT(HolderLookup.Provider lookupProvider, CompoundTag tag) {
             nonBlockingJobsRunningAmount.putInt(String.valueOf(entry.getIntKey()), entry.getIntValue());
         }
         tag.put("nonBlockingJobsRunningAmount", nonBlockingJobsRunningAmount);
+
+        CompoundTag recipeDurationStatistics = new CompoundTag();
+        getRecipeDurationStatistics().writeToNBT(recipeDurationStatistics);
+        tag.put("recipeDurationStatistics", recipeDurationStatistics);
     }
 
     public void readFromNBT(HolderLookup.Provider lookupProvider, CompoundTag tag) {
@@ -221,6 +236,12 @@ public void readFromNBT(HolderLookup.Provider lookupProvider, CompoundTag tag) {
                     craftingJob.getId(),
                     pendingIngredientInstanceEntries);
 
+            if (entryTag.contains("pendingIngredientInstanceEntryStartTicks", Tag.TAG_LONG_ARRAY)) {
+                this.processingCraftingJobsStartTicks.put(
+                        craftingJob.getId(),
+                        new LongArrayList(entryTag.getLongArray("pendingIngredientInstanceEntryStartTicks")));
+            }
+
         }
 
         ListTag pendingCraftingJobs = tag.getList("pendingCraftingJobs", Tag.TAG_COMPOUND);
@@ -260,6 +281,8 @@ public void readFromNBT(HolderLookup.Provider lookupProvider, CompoundTag tag) {
             int amount = nonBlockingJobsRunningAmount.getInt(key);
             this.nonBlockingJobsRunningAmount.put(craftingJobId, amount);
         }
+
+        getRecipeDurationStatistics().readFromNBT(tag.getCompound("recipeDurationStatistics"));
     }
 
     public boolean setBlockingJobsMode(boolean blockingJobsMode) {
@@ -316,9 +339,63 @@ public Collection<CraftingJob> getPendingCraftingJobs() {
         return pendingCraftingJobs.values();
     }
 
+    /**
+     * @param craftingJobId A crafting job id.
+     * @return The tick at which the oldest running crafting operation of the given job was started,
+     *         or -1 if no operation is running.
+     */
+    public long getCraftingJobEntryStartTick(int craftingJobId) {
+        LongList startTicks = this.processingCraftingJobsStartTicks.get(craftingJobId);
+        return startTicks == null || startTicks.isEmpty() ? -1 : startTicks.getLong(0);
+    }
+
+    /**
+     * @param recipe A recipe.
+     * @return The estimated duration in ticks of a single crafting operation of the given recipe,
+     *         based on the operations that were performed by this handler before, or -1 if unknown.
+     *         This falls back to the average duration over all recipes
+     *         when the given recipe itself was not crafted recently.
+     */
+    public long getEstimatedRecipeDuration(IRecipeDefinition recipe) {
+        return getRecipeDurationStatistics().getEstimatedDuration(recipe, getCurrentTick());
+    }
+
+    /**
+     * @return The current game tick.
+     */
+    protected long getCurrentTick() {
+        return CraftingHelpers.getCurrentTick();
+    }
+
+    /**
+     * Take the duration of a finished crafting operation into account for future estimations.
+     * @param recipe The recipe that was crafted.
+     * @param durationTicks The number of ticks the crafting operation took.
+     */
+    protected void reportRecipeDuration(IRecipeDefinition recipe, long durationTicks) {
+        getRecipeDurationStatistics().reportDuration(recipe, durationTicks, getCurrentTick());
+    }
+
+    /**
+     * @return The duration statistics of this handler, which are created lazily,
+     *         as their configuration is only available once the mod is fully loaded.
+     */
+    public RecipeDurationStatistics getRecipeDurationStatistics() {
+        if (this.recipeDurationStatistics == null) {
+            this.recipeDurationStatistics = createRecipeDurationStatistics();
+        }
+        return this.recipeDurationStatistics;
+    }
+
+    protected RecipeDurationStatistics createRecipeDurationStatistics() {
+        return new RecipeDurationStatistics(GeneralConfig.craftingInterfaceRecipeDurationEntries,
+                GeneralConfig.craftingInterfaceRecipeDurationMaxAge);
+    }
+
     public void unmarkCraftingJobProcessing(CraftingJob craftingJob) {
         if (this.processingCraftingJobs.remove(craftingJob.getId()) != null) {
             this.processingCraftingJobsPendingIngredients.remove(craftingJob.getId());
+            this.processingCraftingJobsStartTicks.remove(craftingJob.getId());
             this.pendingCraftingJobs.put(craftingJob.getId(), craftingJob);
         }
     }
@@ -331,6 +408,7 @@ public void addCraftingJobProcessingPendingIngredientsEntry(CraftingJob crafting
             this.allCraftingJobs.remove(craftingJob.getId());
             this.nonBlockingJobsRunningAmount.remove(craftingJob.getId());
             this.processingCraftingJobsPendingIngredients.remove(craftingJob.getId());
+            this.processingCraftingJobsStartTicks.remove(craftingJob.getId());
 
         } else {
             this.processingCraftingJobs.put(craftingJob.getId(), craftingJob);
@@ -342,6 +420,14 @@ public void addCraftingJobProcessingPendingIngredientsEntry(CraftingJob crafting
                 this.processingCraftingJobsPendingIngredients.put(craftingJob.getId(), pendingIngredientsEntries);
             }
             pendingIngredientsEntries.add(pendingIngredients);
+
+            // Remember when this crafting operation started, so that its duration can be measured once it finishes
+            LongList startTicks = this.processingCraftingJobsStartTicks.get(craftingJob.getId());
+            if (startTicks == null) {
+                startTicks = new LongArrayList();
+                this.processingCraftingJobsStartTicks.put(craftingJob.getId(), startTicks);
+            }
+            startTicks.add(getCurrentTick());
         }
     }
 
@@ -378,6 +464,7 @@ protected <T, M> void unregisterIngredientObserver(IngredientComponent<T, M> ing
 
     public void onCraftingJobFinished(CraftingJob craftingJob) {
         this.processingCraftingJobs.remove(craftingJob.getId());
+        this.processingCraftingJobsStartTicks.remove(craftingJob.getId());
         this.pendingCraftingJobs.remove(craftingJob.getId());
         this.finishedCraftingJobs.put(craftingJob.getId(), craftingJob);
         this.allCraftingJobs.put(craftingJob.getId(), craftingJob);
@@ -386,6 +473,7 @@ public void onCraftingJobFinished(CraftingJob craftingJob) {
     // This does the same as above, just based on crafting job id
     public void markCraftingJobFinished(int craftingJobId) {
         this.processingCraftingJobsPendingIngredients.remove(craftingJobId);
+        this.processingCraftingJobsStartTicks.remove(craftingJobId);
         this.processingCraftingJobs.remove(craftingJobId);
         this.pendingCraftingJobs.remove(craftingJobId);
 
@@ -399,6 +487,17 @@ public void onCraftingJobEntryFinished(ICraftingNetwork craftingNetwork, int cra
         CraftingJob craftingJob = this.allCraftingJobs.get(craftingJobId);
         craftingJob.setAmount(craftingJob.getAmount() - 1);
 
+        // Measure how long this crafting operation took, so that future jobs for this recipe can be estimated.
+        // Operations don't necessarily finish in the order in which they were started,
+        // but as they all apply to the same recipe, the oldest one can safely be used.
+        LongList startTicks = this.processingCraftingJobsStartTicks.get(craftingJobId);
+        if (startTicks != null && !startTicks.isEmpty()) {
+            reportRecipeDuration(craftingJob.getRecipe(), getCurrentTick() - startTicks.removeLong(0));
+            if (startTicks.isEmpty()) {
+                this.processingCraftingJobsStartTicks.remove(craftingJobId);
+            }
+        }
+
         if (this.nonBlockingJobsRunningAmount.containsKey(craftingJobId)) {
             this.nonBlockingJobsRunningAmount.put(craftingJobId, this.nonBlockingJobsRunningAmount.get(craftingJobId) - 1);
         }