From 2a49fdee7f2cf1774953f6e04f5699e31eefa63c Mon Sep 17 00:00:00 2001 From: James Seibel Date: Tue, 28 Oct 2025 07:46:53 -0500 Subject: [PATCH] Add experimental loading option and perfRecorder --- .../distanthorizons/core/config/Config.java | 13 ++ .../core/render/LodQuadTree.java | 6 + .../core/render/LodRenderSection.java | 64 ++++-- .../core/util/PerfRecorder.java | 185 ++++++++++++++++++ .../assets/distanthorizons/lang/en_us.json | 5 + 5 files changed, 259 insertions(+), 14 deletions(-) create mode 100644 core/src/main/java/com/seibel/distanthorizons/core/util/PerfRecorder.java 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 e331ce356..1cb36fae5 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 @@ -839,6 +839,19 @@ public class Config + "will be set to 0 (disabled).") .addListener(WorldCurvatureConfigEventHandler.INSTANCE) .build(); + + // TODO should be replaced with a better long-term solution + @Deprecated + public static ConfigEntry onlyLoadCenterLods = new ConfigEntry.Builder() + .set(false) + .comment("" + + "For internal testing:\n" + + "Skips loading adjacent LODs to significantly reduce load times (~5x)\n" + + "but causes lighting on LOD borders to appear as full-bright\n" + + "and other graphical bugs.\n" + + "") + .addListener(ReloadLodsConfigEventHandler.DELAYED_INSTANCE) + .build(); } } diff --git a/core/src/main/java/com/seibel/distanthorizons/core/render/LodQuadTree.java b/core/src/main/java/com/seibel/distanthorizons/core/render/LodQuadTree.java index f9bd34f86..17d16598c 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/render/LodQuadTree.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/render/LodQuadTree.java @@ -38,6 +38,7 @@ import com.seibel.distanthorizons.core.render.renderer.generic.BeaconRenderHandl import com.seibel.distanthorizons.core.render.renderer.generic.GenericObjectRenderer; import com.seibel.distanthorizons.core.util.KeyedLockContainer; import com.seibel.distanthorizons.core.util.LodUtil; +import com.seibel.distanthorizons.core.util.PerfRecorder; import com.seibel.distanthorizons.core.util.ThreadUtil; import com.seibel.distanthorizons.core.util.objects.quadTree.QuadNode; import com.seibel.distanthorizons.core.util.objects.quadTree.QuadTree; @@ -121,6 +122,9 @@ public class LodQuadTree extends QuadTree implements IDebugRen @Nullable public final BeaconRenderHandler beaconRenderHandler; + // TODO should be removed once James is done testing + @Deprecated + public static final PerfRecorder FILE_PERF_RECORDER = new PerfRecorder("File"); /** the smallest numerical detail level number that can be rendered */ private byte maxRenderDetailLevel; @@ -154,6 +158,8 @@ public class LodQuadTree extends QuadTree implements IDebugRen GenericObjectRenderer genericObjectRenderer = this.level.getGenericRenderer(); this.beaconRenderHandler = (genericObjectRenderer != null) ? new BeaconRenderHandler(genericObjectRenderer) : null; + FILE_PERF_RECORDER.clear(); + } diff --git a/core/src/main/java/com/seibel/distanthorizons/core/render/LodRenderSection.java b/core/src/main/java/com/seibel/distanthorizons/core/render/LodRenderSection.java index 494cb7c66..3842b1ab2 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/render/LodRenderSection.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/render/LodRenderSection.java @@ -45,6 +45,7 @@ import com.seibel.distanthorizons.core.render.renderer.generic.BeaconRenderHandl import com.seibel.distanthorizons.core.sql.dto.BeaconBeamDTO; import com.seibel.distanthorizons.core.sql.repo.BeaconBeamRepo; import com.seibel.distanthorizons.core.util.KeyedLockContainer; +import com.seibel.distanthorizons.core.util.PerfRecorder; import com.seibel.distanthorizons.core.util.threading.PriorityTaskPicker; import com.seibel.distanthorizons.core.util.threading.ThreadPoolUtil; import com.seibel.distanthorizons.core.wrapperInterfaces.minecraft.IMinecraftClientWrapper; @@ -133,6 +134,9 @@ public class LodRenderSection implements IDebugRenderable, AutoCloseable private boolean checkedIfFullDataSourceExists = false; private boolean fullDataSourceExists = false; + @Deprecated + public final PerfRecorder filePerfRecorder = LodQuadTree.FILE_PERF_RECORDER; + //=============// @@ -240,7 +244,7 @@ public class LodRenderSection implements IDebugRenderable, AutoCloseable private CompletableFuture getAndUploadRenderDataToGpuAsync() { // get the center pos data - return this.getRenderSourceForPosAsync(this.pos) + return this.getRenderSourceForPosAsync(this.pos, null) .thenCompose((CachedColumnRenderSource cachedRenderSource) -> { try @@ -260,19 +264,33 @@ public class LodRenderSection implements IDebugRenderable, AutoCloseable LodQuadBuilder lodQuadBuilder = new LodQuadBuilder(enableTransparency, this.level.getClientLevelWrapper()); + PerfRecorder.Timer getAdj = this.filePerfRecorder.start("getAdj"); + // get the adjacent positions // needs to be done async to prevent threads waiting on the same positions to be processed final CompletableFuture[] adjacentLoadFutures = new CompletableFuture[4]; - adjacentLoadFutures[0] = this.getRenderSourceForPosAsync(DhSectionPos.getAdjacentPos(this.pos, EDhDirection.NORTH)); - adjacentLoadFutures[1] = this.getRenderSourceForPosAsync(DhSectionPos.getAdjacentPos(this.pos, EDhDirection.SOUTH)); - adjacentLoadFutures[2] = this.getRenderSourceForPosAsync(DhSectionPos.getAdjacentPos(this.pos, EDhDirection.EAST)); - adjacentLoadFutures[3] = this.getRenderSourceForPosAsync(DhSectionPos.getAdjacentPos(this.pos, EDhDirection.WEST)); - //adjacentLoadFutures[0] = CompletableFuture.completedFuture(null); - //adjacentLoadFutures[1] = CompletableFuture.completedFuture(null); - //adjacentLoadFutures[2] = CompletableFuture.completedFuture(null); - //adjacentLoadFutures[3] = CompletableFuture.completedFuture(null); + + if (Config.Client.Advanced.Graphics.Experimental.onlyLoadCenterLods.get()) + { + // TODO temporary test, long term something else should be done to so we can get adjacent lighting data + // probably a change to the LOD data format + adjacentLoadFutures[0] = CompletableFuture.completedFuture(null); + adjacentLoadFutures[1] = CompletableFuture.completedFuture(null); + adjacentLoadFutures[2] = CompletableFuture.completedFuture(null); + adjacentLoadFutures[3] = CompletableFuture.completedFuture(null); + } + else + { + adjacentLoadFutures[0] = this.getRenderSourceForPosAsync(this.pos, EDhDirection.NORTH); + adjacentLoadFutures[1] = this.getRenderSourceForPosAsync(this.pos, EDhDirection.SOUTH); + adjacentLoadFutures[2] = this.getRenderSourceForPosAsync(this.pos, EDhDirection.EAST); + adjacentLoadFutures[3] = this.getRenderSourceForPosAsync(this.pos, EDhDirection.WEST); + } + return CompletableFuture.allOf(adjacentLoadFutures).thenRun(() -> { + getAdj.end(); + try (CachedColumnRenderSource northRenderSource = adjacentLoadFutures[0].get(); CachedColumnRenderSource southRenderSource = adjacentLoadFutures[1].get(); CachedColumnRenderSource eastRenderSource = adjacentLoadFutures[2].get(); @@ -292,8 +310,13 @@ public class LodRenderSection implements IDebugRenderable, AutoCloseable // the render sources are only needed by this synchronous method, // then they can be closed + PerfRecorder.Timer makeRender = this.filePerfRecorder.start("makeRender"); ColumnRenderBufferBuilder.makeLodRenderData(lodQuadBuilder, thisRenderSource, this.level, adjacentRenderSections, adjIsSameDetailLevel); + makeRender.end(); + + PerfRecorder.Timer upload = this.filePerfRecorder.start("upload"); this.uploadToGpuAsync(lodQuadBuilder); + upload.end(); } catch (Exception e) { @@ -314,9 +337,16 @@ public class LodRenderSection implements IDebugRenderable, AutoCloseable }); } /** async is done so each thread can run without waiting on others */ - private CompletableFuture getRenderSourceForPosAsync(long pos) + private CompletableFuture getRenderSourceForPosAsync(long pos, @Nullable EDhDirection direction) { - ReentrantLock lock = this.renderLoadLockContainer.getLockForPos(pos); + if (direction != null) + { + pos = DhSectionPos.getAdjacentPos(pos, direction); + } + final long finalPos = pos; + + + ReentrantLock lock = this.renderLoadLockContainer.getLockForPos(finalPos); try { // we don't want multiple threads attempting to load the same position at the same time, @@ -324,7 +354,7 @@ public class LodRenderSection implements IDebugRenderable, AutoCloseable lock.lock(); // use the cached data if possible - CachedColumnRenderSource existingCachedRenderSource = this.cachedRenderSourceByPos.getIfPresent(pos); + CachedColumnRenderSource existingCachedRenderSource = this.cachedRenderSourceByPos.getIfPresent(finalPos); if (existingCachedRenderSource != null) { existingCachedRenderSource.markInUse(); @@ -346,14 +376,20 @@ public class LodRenderSection implements IDebugRenderable, AutoCloseable final CachedColumnRenderSource newCachedRenderSource = new CachedColumnRenderSource(loadFuture, lock, this.cachedRenderSourceByPos); executor.execute(() -> { + PerfRecorder.Timer getFull = this.filePerfRecorder.start("getFull"); + // generate new render source - try (FullDataSourceV2 fullDataSource = this.fullDataSourceProvider.get(pos)) + try (FullDataSourceV2 fullDataSource = this.fullDataSourceProvider.get(finalPos)) { + getFull.end(); + + PerfRecorder.Timer transform = this.filePerfRecorder.start("transform"); newCachedRenderSource.columnRenderSource = FullDataToRenderDataTransformer.transformFullDataToRenderSource(fullDataSource, this.levelWrapper); + transform.end(); } catch (Exception e) { - LOGGER.error("Unexpected issue creating render data for pos: ["+DhSectionPos.toString(pos)+"], error: ["+e.getMessage()+"].", e); + LOGGER.error("Unexpected issue creating render data for pos: ["+DhSectionPos.toString(finalPos)+"], error: ["+e.getMessage()+"].", e); } finally { diff --git a/core/src/main/java/com/seibel/distanthorizons/core/util/PerfRecorder.java b/core/src/main/java/com/seibel/distanthorizons/core/util/PerfRecorder.java new file mode 100644 index 000000000..d56734b27 --- /dev/null +++ b/core/src/main/java/com/seibel/distanthorizons/core/util/PerfRecorder.java @@ -0,0 +1,185 @@ +package com.seibel.distanthorizons.core.util; + +import com.seibel.distanthorizons.core.logging.DhLogger; +import com.seibel.distanthorizons.core.logging.DhLoggerBuilder; + +import java.text.DecimalFormat; +import java.util.ArrayList; +import java.util.Comparator; +import java.util.Enumeration; +import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.LongAdder; + +/** + * Can be used to track relative performance when attempting to optimize specific methods.
+ * Example:
+ * + * PerfRecorder.Timer upload = this.filePerfRecorder.start("upload");
+ * this.uploadToGpuAsync(lodQuadBuilder);
+ * upload.end();
+ * + *
+ * Note: there is some overhead to the timers starting/ending + * so times will not be exact, especially in very fast methods.
+ * In those contexts a dedicated profiler will be better. + */ +public class PerfRecorder +{ + private static final int TOTAL_WIDTH = 7; + /** + * Examples:
+ * + * "123,456"
+ * " 3,456"
+ * " 456"
+ * " 6"
+ * + */ + private static final DecimalFormat DECIMAL_FORMAT = new DecimalFormat("###,###"); + + + /** + * different loggers are needed for each recorder + * to prevent them from all sharing the same + * {@link DhLogger#canLog()} limit. + */ + private final DhLogger logger; + + public final String name; + + public final ConcurrentHashMap nanoPerId = new ConcurrentHashMap<>(); + public String lastPerfLog = ""; + + + + //=============// + // constructor // + //=============// + + public PerfRecorder(String name) + { + this.name = name; + + this.logger = new DhLoggerBuilder() + .name(PerfRecorder.class.getSimpleName()+"-"+this.name) + .maxCountPerSecond(1) + .build(); + } + + + + //=====================// + // performance logging // + //=====================// + + public Timer start(String id) { return new Timer(id); } + + public void clear() { this.nanoPerId.clear(); } + + /** + * Will log if the message changed + * and enough time has passed as defined by + * the parent {@link DhLogger#canLog} + */ + public void tryLog() + { + if (this.logger.canLog()) + { + String perfTime = this.toString(); + if (!perfTime.equals(this.lastPerfLog)) + { + this.lastPerfLog = perfTime; + this.logger.info(perfTime); + } + } + } + + + + //===================// + // default overrides // + //===================// + + @Override + public String toString() + { + // sort keys + // (done so we can easily and consistently compare different runs) + ArrayList sortedKeys = new ArrayList<>(); + Enumeration keyEnumerator = this.nanoPerId.keys(); + while (keyEnumerator.hasMoreElements()) + { + sortedKeys.add(keyEnumerator.nextElement()); + } + sortedKeys.sort(Comparator.naturalOrder()); + + + + // build the string + StringBuilder builder = new StringBuilder(); + long totalNanoTime = 0; + + for(String id : sortedKeys) + { + // convert nanoseconds to milliseconds for easier reading + LongAdder nanoTimeAdder = this.nanoPerId.get(id); + long nsTime = nanoTimeAdder.sum(); + long msTime = TimeUnit.MILLISECONDS.convert(nsTime, TimeUnit.NANOSECONDS); + totalNanoTime += nsTime; + + String line = id+"["+formatNumber(msTime)+"] "; + builder.append(line); + } + + // add the total time + long totalMsTime = TimeUnit.MILLISECONDS.convert(totalNanoTime, TimeUnit.NANOSECONDS); + return "Total["+formatNumber(totalMsTime)+"] " + builder.toString(); + } + private static String formatNumber(long number) + { + String formattedNumber = DECIMAL_FORMAT.format(number); + return String.format("%" + TOTAL_WIDTH + "s", formattedNumber); + } + + + + //==============// + // helper class // + //==============// + + public class Timer + { + protected final String id; + protected final long startTime; + + + + //=============// + // constructor // + //=============// + + private Timer(String id) + { + this.id = id; + this.startTime = System.nanoTime(); + } + + + //===============// + // timer methods // + //===============// + + public void end() + { + long endTime = System.nanoTime(); + long totalNano = endTime - this.startTime; + + LongAdder nsAdder = PerfRecorder.this.nanoPerId.computeIfAbsent(this.id, (String id) -> new LongAdder()); + nsAdder.add(totalNano); + } + } + + + +} 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 2975ac46e..6c7f85efa 100644 --- a/core/src/main/resources/assets/distanthorizons/lang/en_us.json +++ b/core/src/main/resources/assets/distanthorizons/lang/en_us.json @@ -395,6 +395,11 @@ "distanthorizons.config.client.advanced.graphics.experimental.earthCurveRatio.@tooltip": "A value of 1 is equivalent to the curvature of Earth in real life. \nThe minimum accepted value is 50 and the maximum value is 5000. \nEverything between 1 and 49 will be rounded up to 50.", + "distanthorizons.config.client.advanced.graphics.experimental.onlyLoadCenterLods": + "Only load center LODs", + "distanthorizons.config.client.advanced.graphics.experimental.onlyLoadCenterLods.@tooltip": + "Skips loading adjacent LODs to significantly reduce load times (~5x)\nbut causes lighting on LOD borders to appear as full-bright\nand other graphical bugs.\n", + "distanthorizons.config.client.advanced.autoUpdater":