From c89abd414b9ace91559677b25e6ba266b497aa0f Mon Sep 17 00:00:00 2001 From: James Seibel Date: Wed, 18 Mar 2026 07:45:42 -0500 Subject: [PATCH] Add render task profiling --- .../distanthorizons/core/config/Config.java | 5 ++ .../core/logging/f3/F3Screen.java | 8 ++ .../core/render/RenderThreadTaskHandler.java | 87 +++++++++++++++++-- .../core/util/objects/RollingAverage.java | 20 +++++ .../assets/distanthorizons/lang/en_us.json | 2 + 5 files changed, 116 insertions(+), 6 deletions(-) diff --git a/core/src/main/java/com/seibel/distanthorizons/core/config/Config.java b/core/src/main/java/com/seibel/distanthorizons/core/config/Config.java index 0d750ca10..85213a20c 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/config/Config.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/config/Config.java @@ -1151,6 +1151,11 @@ public class Config .comment("Shows info about each thread pool.") .build(); + public static ConfigEntry showRenderThreadTasks = new ConfigEntry.Builder() + .set(false) + .comment("Shows info about the render thread tasks.") + .build(); + public static ConfigEntry showCombinedObjectPools = new ConfigEntry.Builder() .set(false) .comment("Shows the combined memory use and array counts for all DH pooled objects.") diff --git a/core/src/main/java/com/seibel/distanthorizons/core/logging/f3/F3Screen.java b/core/src/main/java/com/seibel/distanthorizons/core/logging/f3/F3Screen.java index 49d9026ee..ec8b5a0c2 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/logging/f3/F3Screen.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/logging/f3/F3Screen.java @@ -28,6 +28,7 @@ import com.seibel.distanthorizons.core.jar.ModJarInfo; import com.seibel.distanthorizons.core.level.IDhClientLevel; import com.seibel.distanthorizons.core.level.IDhLevel; import com.seibel.distanthorizons.core.logging.DhLoggerBuilder; +import com.seibel.distanthorizons.core.render.RenderThreadTaskHandler; import com.seibel.distanthorizons.core.util.objects.pooling.PhantomArrayListPool; import com.seibel.distanthorizons.core.pos.DhSectionPos; import com.seibel.distanthorizons.core.render.RenderBufferHandler; @@ -149,6 +150,13 @@ public class F3Screen messageList.add(""); } + // render thread tasks + if (Config.Client.Advanced.Debugging.F3Screen.showRenderThreadTasks.get()) + { + RenderThreadTaskHandler.INSTANCE.addDebugMenuStringsToList(messageList); + messageList.add(""); + } + // combined object pools if (Config.Client.Advanced.Debugging.F3Screen.showCombinedObjectPools.get()) { diff --git a/core/src/main/java/com/seibel/distanthorizons/core/render/RenderThreadTaskHandler.java b/core/src/main/java/com/seibel/distanthorizons/core/render/RenderThreadTaskHandler.java index fecadf284..3d9bcecea 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/render/RenderThreadTaskHandler.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/render/RenderThreadTaskHandler.java @@ -2,16 +2,24 @@ package com.seibel.distanthorizons.core.render; import com.seibel.distanthorizons.core.config.Config; import com.seibel.distanthorizons.core.dependencyInjection.SingletonInjector; +import com.seibel.distanthorizons.core.enums.MinecraftTextFormat; import com.seibel.distanthorizons.core.logging.DhLogger; import com.seibel.distanthorizons.core.logging.DhLoggerBuilder; +import com.seibel.distanthorizons.core.logging.f3.F3Screen; import com.seibel.distanthorizons.core.util.TimerUtil; +import com.seibel.distanthorizons.core.util.objects.RollingAverage; import com.seibel.distanthorizons.core.wrapperInterfaces.minecraft.IMinecraftClientWrapper; import com.seibel.distanthorizons.core.wrapperInterfaces.minecraft.IMinecraftRenderWrapper; +import com.seibel.distanthorizons.core.wrapperInterfaces.minecraft.IProfilerWrapper; import com.seibel.distanthorizons.coreapi.ModInfo; import org.jetbrains.annotations.Nullable; +import java.text.NumberFormat; +import java.util.List; import java.util.Timer; +import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.ConcurrentLinkedQueue; +import java.util.concurrent.atomic.LongAdder; public class RenderThreadTaskHandler { @@ -19,7 +27,9 @@ public class RenderThreadTaskHandler .fileLevelConfig(Config.Common.Logging.logRendererEventToFile) .build(); - private static final ConcurrentLinkedQueue RENDER_THREAD_RUNNABLE_QUEUE = new ConcurrentLinkedQueue<>(); + private static final ConcurrentLinkedQueue RENDER_THREAD_RUNNABLE_QUEUE = new ConcurrentLinkedQueue<>(); + private static final ConcurrentHashMap AVERAGE_MS_RUN_TIME_BY_TASK_NAME = new ConcurrentHashMap<>(); + private static final LongAdder COMPLETED_TASK_COUNTER = new LongAdder(); private static final Timer TIMER = TimerUtil.CreateTimer("Cleanup timer"); private static final long MS_BETWEEN_CLEANUP_TICKS = 1_000L; @@ -29,7 +39,7 @@ public class RenderThreadTaskHandler public static final RenderThreadTaskHandler INSTANCE = new RenderThreadTaskHandler(); - private long msSinceGlTasksRun = System.currentTimeMillis(); + private long msSinceTasksRun = System.currentTimeMillis(); @@ -93,9 +103,9 @@ public class RenderThreadTaskHandler private void runRenderThreadTasks(long msMaxRunTime) { long startTimeMs = System.currentTimeMillis(); - this.msSinceGlTasksRun = startTimeMs; + this.msSinceTasksRun = startTimeMs; - Runnable runnable = RENDER_THREAD_RUNNABLE_QUEUE.poll(); + QueuedRunnable runnable = RENDER_THREAD_RUNNABLE_QUEUE.poll(); while(runnable != null) { runnable.run(); @@ -103,6 +113,19 @@ public class RenderThreadTaskHandler // only try running for a limited amount of time to prevent lag spikes long currentTimeMs = System.currentTimeMillis(); long runDuration = currentTimeMs - startTimeMs; + + // stat tracking + if (ModInfo.IS_DEV_BUILD) + { + if (!AVERAGE_MS_RUN_TIME_BY_TASK_NAME.containsKey(runnable.name)) + { + AVERAGE_MS_RUN_TIME_BY_TASK_NAME.put(runnable.name, new RollingAverage(1_000)); + } + AVERAGE_MS_RUN_TIME_BY_TASK_NAME.get(runnable.name).add(runDuration); + + COMPLETED_TASK_COUNTER.increment(); + } + if (runDuration > msMaxRunTime) { break; @@ -119,7 +142,7 @@ public class RenderThreadTaskHandler private void manualCleanupTick() { long nowMs = System.currentTimeMillis(); - long msSinceLast = nowMs - this.msSinceGlTasksRun; + long msSinceLast = nowMs - this.msSinceTasksRun; if (msSinceLast < MS_BEFORE_RUN_CLEANUP_TIMER) { return; @@ -130,13 +153,65 @@ public class RenderThreadTaskHandler // Run the queued tasks on MC's executor (hopefully this should always run, // even if DH's render code isn't being hit). IMinecraftClientWrapper MC = SingletonInjector.INSTANCE.get(IMinecraftClientWrapper.class); - MC.executeOnRenderThread(() -> this.runRenderThreadTasks(1_000)); + MC.executeOnRenderThread(() -> this.runRenderThreadTasks(250)); } //endregion + //===========// + // debugging // + //===========// + ///region + + public void addDebugMenuStringsToList(List messageList) + { + if (!ModInfo.IS_DEV_BUILD) + { + return; + } + + + String o = MinecraftTextFormat.ORANGE; + String g = MinecraftTextFormat.GREEN; + String b = MinecraftTextFormat.DARK_BLUE; + String y = MinecraftTextFormat.YELLOW; + String cf = MinecraftTextFormat.CLEAR_FORMATTING; + + + + NumberFormat numberFormat = F3Screen.NUMBER_FORMAT; + + String queueSize = numberFormat.format(RENDER_THREAD_RUNNABLE_QUEUE.size()); + String completedCount = numberFormat.format(COMPLETED_TASK_COUNTER.sum()); + + String messageHeader = "Render Tasks, Queue: "+o+queueSize+cf+", Done: "+g+completedCount+cf; + messageList.add(messageHeader); + + AVERAGE_MS_RUN_TIME_BY_TASK_NAME.forEach((name, rollingAverage) -> + { + // thread runtime + String runTimeAvgStr; + double runTimeAvgInMs = rollingAverage.getAverage(); + if (!Double.isNaN(runTimeAvgInMs)) + { + runTimeAvgStr = numberFormat.format(runTimeAvgInMs); + } + else + { + runTimeAvgStr = "<0"; + } + + String message = name+" Avg: "+b+runTimeAvgStr+"ms"+cf+" #: "+y+rollingAverage.getLifetimeCount()+cf; + messageList.add(message); + }); + } + + ///endregion + + + //================// // helper classes // //================// diff --git a/core/src/main/java/com/seibel/distanthorizons/core/util/objects/RollingAverage.java b/core/src/main/java/com/seibel/distanthorizons/core/util/objects/RollingAverage.java index 17de541cf..da03297ba 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/util/objects/RollingAverage.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/util/objects/RollingAverage.java @@ -17,12 +17,15 @@ public class RollingAverage private int index = 0; private double sum = 0.0; private final Lock arrayLock = new ReentrantLock(); + /** how many items have been added to this average over its lifetime */ + private long lifetimeCount = 0; //=============// // constructor // //=============// + //region public RollingAverage(int size) { @@ -35,11 +38,14 @@ public class RollingAverage this.values = new double[size]; } + //endregion + //=======// // input // //=======// + //region public void add(double value) { @@ -56,6 +62,8 @@ public class RollingAverage this.index = (this.index + 1) % this.maxSize; this.currentSize = Math.max(this.index+1, this.currentSize); + + this.lifetimeCount++; } finally { @@ -71,6 +79,7 @@ public class RollingAverage this.sum = 0; this.index = 0; this.currentSize = 0; + this.lifetimeCount = 0; Arrays.fill(this.values, 0); } finally @@ -79,11 +88,14 @@ public class RollingAverage } } + //endregion + //========// // output // //========// + //region /** Gets the current rolling average. */ public double getAverage() @@ -101,14 +113,22 @@ public class RollingAverage /** rounded to two decimals*/ public String getAverageRoundedString() { return String.format("%.2f", this.getAverage()); } + public long getLifetimeCount() { return this.lifetimeCount; } + + //endregion + //================// // base overrides // //================// + //region @Override public String toString() { return "avg: ["+this.getAverageRoundedString()+"], count: ["+this.currentSize+"], max count: ["+this.maxSize+"]."; } + //endregion + + } diff --git a/core/src/main/resources/assets/distanthorizons/lang/en_us.json b/core/src/main/resources/assets/distanthorizons/lang/en_us.json index 79dd4d1ae..35ac1763f 100644 --- a/core/src/main/resources/assets/distanthorizons/lang/en_us.json +++ b/core/src/main/resources/assets/distanthorizons/lang/en_us.json @@ -573,6 +573,8 @@ "Player Section Pos Detail Level", "distanthorizons.config.client.advanced.debugging.f3Screen.showThreadPools": "Show Thread Pools", + "distanthorizons.config.client.advanced.debugging.f3Screen.showRenderThreadTasks": + "Show Render Thread Tasks", "distanthorizons.config.client.advanced.debugging.f3Screen.showCombinedObjectPools": "Show Combined Object Pools", "distanthorizons.config.client.advanced.debugging.f3Screen.showSeparatedObjectPools":