From eb7b03fbfe8ab850ca6be4213e5a2119cfaea63e Mon Sep 17 00:00:00 2001 From: James Seibel Date: Thu, 9 Jan 2025 17:19:49 -0600 Subject: [PATCH] fix some data sources not being caught and closed This should further reduce the max memory needed. DelayedFullDataSourceSaveCache is problematic due to not properly closing all data sources it creates and has been deprecated and removed. --- .../FullDataToRenderDataTransformer.java | 1 - .../core/file/AbstractDataSourceHandler.java | 50 ++-- .../DelayedFullDataSourceSaveCache.java | 167 ++++++++----- .../FullDataSourceProviderV2.java | 16 +- .../GeneratedFullDataSourceProvider.java | 37 +-- .../RemoteFullDataSourceProvider.java | 2 +- .../core/level/AbstractDhLevel.java | 56 +++-- .../core/level/AbstractDhServerLevel.java | 2 +- .../distanthorizons/core/level/IDhLevel.java | 6 - .../pooling/PhantomArrayListCheckout.java | 16 ++ .../core/pooling/PhantomArrayListPool.java | 222 ++++++++++++------ 11 files changed, 323 insertions(+), 252 deletions(-) diff --git a/core/src/main/java/com/seibel/distanthorizons/core/dataObjects/transformers/FullDataToRenderDataTransformer.java b/core/src/main/java/com/seibel/distanthorizons/core/dataObjects/transformers/FullDataToRenderDataTransformer.java index 5e17af7b6..533409c82 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/dataObjects/transformers/FullDataToRenderDataTransformer.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/dataObjects/transformers/FullDataToRenderDataTransformer.java @@ -164,7 +164,6 @@ public class FullDataToRenderDataTransformer } else { - // new LongArrayList(new long[fullDataLength]) PhantomArrayListCheckout checkout = ARRAY_LIST_POOL.checkoutArrays(0, 0, 1); LongArrayList dataArrayList = checkout.getLongArray(0, fullDataLength); diff --git a/core/src/main/java/com/seibel/distanthorizons/core/file/AbstractDataSourceHandler.java b/core/src/main/java/com/seibel/distanthorizons/core/file/AbstractDataSourceHandler.java index 267d822aa..b2b24f9b7 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/file/AbstractDataSourceHandler.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/file/AbstractDataSourceHandler.java @@ -69,8 +69,6 @@ public abstract class AbstractDataSourceHandler public final ArrayList> dateSourceUpdateListeners = new ArrayList<>(); - public final ConcurrentHashMap> updateDataSourceFutureByPos = new ConcurrentHashMap<>(); - //=============// @@ -186,6 +184,17 @@ public abstract class AbstractDataSourceHandler // data updating // //===============// + /** + * Can be used if the same thread is already handling IO and/or LOD generation. + * Otherwise the async version {@link AbstractDataSourceHandler#updateDataSourceAsync(FullDataSourceV2)} may be a better choice. + */ + public void updateDataSource(@NotNull FullDataSourceV2 inputDataSource) + { this.updateDataSourceAtPos(inputDataSource.getPos(), inputDataSource, true); } + + /** + * Can be used if you don't want to lock the current thread + * Otherwise the sync version {@link AbstractDataSourceHandler#updateDataSource(FullDataSourceV2)} may be a better choice. + */ public CompletableFuture updateDataSourceAsync(@NotNull FullDataSourceV2 inputDataSource) { AbstractExecutorService executor = ThreadPoolUtil.getChunkToLodBuilderExecutor(); @@ -197,35 +206,22 @@ public abstract class AbstractDataSourceHandler try { - return this.updateDataSourceFutureByPos.compute(inputDataSource.getPos(), (Long newPos, CompletableFuture future) -> + this.markUpdateStart(inputDataSource.getPos()); + return CompletableFuture.runAsync(() -> { - if (future != null) + try { - future.cancel(false); - this.markUpdateEnd(newPos); + this.updateDataSourceAtPos(inputDataSource.getPos(), inputDataSource, true); } - - // run file handling on a separate thread - this.markUpdateStart(newPos); - future = CompletableFuture.runAsync(() -> + catch (Exception e) { - try - { - this.updateDataSourceAtPos(newPos, inputDataSource, true); - } - catch (Exception e) - { - LOGGER.error("Unexpected error in async data source update at pos: ["+DhSectionPos.toString(newPos)+"], error: ["+e.getMessage()+"].", e); - } - finally - { - this.markUpdateEnd(newPos); - this.updateDataSourceFutureByPos.remove(newPos); - } - }, executor); - - return future; - }); + LOGGER.error("Unexpected error in async data source update at pos: ["+DhSectionPos.toString(inputDataSource.getPos())+"], error: ["+e.getMessage()+"].", e); + } + finally + { + this.markUpdateEnd(inputDataSource.getPos()); + } + }, executor); } catch (RejectedExecutionException ignore) { diff --git a/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/DelayedFullDataSourceSaveCache.java b/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/DelayedFullDataSourceSaveCache.java index aa59239a9..3e483807a 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/DelayedFullDataSourceSaveCache.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/DelayedFullDataSourceSaveCache.java @@ -10,11 +10,16 @@ import java.util.Timer; import java.util.TimerTask; import java.util.concurrent.CompletableFuture; import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.locks.ReentrantLock; /** * Used to batch together multiple data source updates that all * affect the same position. + * + * @deprecated due to causing data source leaks, however we may still want to re-visit this + * if saving directly is too slow for certain operations (specifically modifying nearby chunks). */ +@Deprecated public class DelayedFullDataSourceSaveCache { private static final Logger LOGGER = DhLoggerBuilder.getLogger(); @@ -26,7 +31,12 @@ public class DelayedFullDataSourceSaveCache private final ConcurrentHashMap saveTimerTasksBySectionPos = new ConcurrentHashMap<>(); private final ConcurrentHashMap> futureBySectionPos = new ConcurrentHashMap<>(); - private final ISaveDataSourceFunc onSaveTimeoutFunc; + protected final ReentrantLock[] saveLockArray; + /** Based on the stack overflow post: https://stackoverflow.com/a/45909920 */ + protected ReentrantLock getSaveLockForPos(long pos) { return this.saveLockArray[Math.abs(Long.hashCode(pos)) % this.saveLockArray.length]; } + + + private final ISaveDataSourceFunc onSaveTimeoutAsyncFunc; private final int saveDelayInMs; @@ -35,10 +45,20 @@ public class DelayedFullDataSourceSaveCache // constructor // //=============// - public DelayedFullDataSourceSaveCache(@NotNull ISaveDataSourceFunc onSaveTimeoutFunc, int saveDelayInMs) + public DelayedFullDataSourceSaveCache(@NotNull ISaveDataSourceFunc onSaveTimeoutAsyncFunc, int saveDelayInMs) { - this.onSaveTimeoutFunc = onSaveTimeoutFunc; + this.onSaveTimeoutAsyncFunc = onSaveTimeoutAsyncFunc; this.saveDelayInMs = saveDelayInMs; + + + // the lock array's length is 2x the number of CPU cores so the number of collisions + // should be relatively low without having too many extra locks + int lockCount = Runtime.getRuntime().availableProcessors() * 2; + this.saveLockArray = new ReentrantLock[lockCount]; + for (int i = 0; i < lockCount; i++) + { + this.saveLockArray[i] = new ReentrantLock(); + } } @@ -53,73 +73,90 @@ public class DelayedFullDataSourceSaveCache */ public CompletableFuture writeDataSourceToMemoryAndQueueSave(FullDataSourceV2 inputDataSource) { - long dataSourcePos = inputDataSource.getPos(); - CompletableFuture future = this.futureBySectionPos.computeIfAbsent(dataSourcePos, (inputPos) -> new CompletableFuture<>()); - - this.dataSourceByPosition.compute(dataSourcePos, (inputPos, memoryDataSource) -> + boolean saveNow = true; + if (saveNow) { - if (memoryDataSource == null) - { - // should not be closed since it will be used by other threads - memoryDataSource = FullDataSourceV2.createEmpty(inputPos); - } + // TODO this doesn't leak, but also doesn't delay the save any + FullDataSourceV2 memoryDataSource = FullDataSourceV2.createEmpty(inputDataSource.getPos()); memoryDataSource.update(inputDataSource); - - - TimerTask timerTask = new TimerTask() - { - @Override - public void run() + return this.onSaveTimeoutAsyncFunc.saveAsync(memoryDataSource) + .handle((voidObj, exception) -> { - DelayedFullDataSourceSaveCache.this.saveTimerTasksBySectionPos.remove(dataSourcePos); - - try - { - FullDataSourceV2 dataSourceToSave = DelayedFullDataSourceSaveCache.this.dataSourceByPosition.remove(dataSourcePos); - if (dataSourceToSave != null) - { - DelayedFullDataSourceSaveCache.this.onSaveTimeoutFunc.save(dataSourceToSave); - } - } - catch (Exception e) // this can throw errors (not exceptions) when installed in Iris' dev environment for some reason due to an issue with LZ4's compression library - { - LOGGER.error("Failed to save updated data for section ["+dataSourcePos+"], error: ["+e.getMessage()+"]", e); - } - finally - { - CompletableFuture future = DelayedFullDataSourceSaveCache.this.futureBySectionPos.remove(dataSourcePos); - if (future != null) - { - future.complete(null); - } - } + memoryDataSource.close(); + return null; + }); + } + else + { + long dataSourcePos = inputDataSource.getPos(); + + CompletableFuture future = this.futureBySectionPos.computeIfAbsent(dataSourcePos, (inputPos) -> new CompletableFuture<>()); + + this.dataSourceByPosition.compute(dataSourcePos, (inputPos, memoryDataSource) -> + { + if (memoryDataSource == null) + { + // should not be closed since it will be used by other threads + memoryDataSource = FullDataSourceV2.createEmpty(inputPos); } - }; - try - { - DELAY_UPDATE_TIMER.schedule(timerTask, this.saveDelayInMs); - } - catch (IllegalStateException ignore) - { - // James isn't sure why this is possible since this logic is inside a lock, - // maybe the timer is just async enough that there can be problems? - //LOGGER.warn("Attempted to queue an already canceled task. Pos: ["+dataSourcePos+"], task already queued for pos: ["+this.saveTimerTasksBySectionPos.containsKey(dataSourcePos)+"]"); - } + memoryDataSource.update(inputDataSource); + + + TimerTask timerTask = new TimerTask() + { + @Override + public void run() + { + DelayedFullDataSourceSaveCache.this.saveTimerTasksBySectionPos.remove(dataSourcePos); + + try + { + FullDataSourceV2 dataSourceToSave = DelayedFullDataSourceSaveCache.this.dataSourceByPosition.remove(dataSourcePos); + if (dataSourceToSave != null) + { + DelayedFullDataSourceSaveCache.this.onSaveTimeoutAsyncFunc.saveAsync(dataSourceToSave); + } + } + catch (Exception e) // this can throw errors (not exceptions) when installed in Iris' dev environment for some reason due to an issue with LZ4's compression library + { + LOGGER.error("Failed to save updated data for section ["+dataSourcePos+"], error: ["+e.getMessage()+"]", e); + } + finally + { + CompletableFuture future = DelayedFullDataSourceSaveCache.this.futureBySectionPos.remove(dataSourcePos); + if (future != null) + { + future.complete(null); + } + } + } + }; + try + { + DELAY_UPDATE_TIMER.schedule(timerTask, this.saveDelayInMs); + } + catch (IllegalStateException ignore) + { + // James isn't sure why this is possible since this logic is inside a lock, + // maybe the timer is just async enough that there can be problems? + //LOGGER.warn("Attempted to queue an already canceled task. Pos: ["+dataSourcePos+"], task already queued for pos: ["+this.saveTimerTasksBySectionPos.containsKey(dataSourcePos)+"]"); + } + + + // cancel the old save timer if present + // (this is equivalent to restarting the timer) + TimerTask oldTask = this.saveTimerTasksBySectionPos.put(dataSourcePos, timerTask); + if (oldTask != null) + { + oldTask.cancel(); + } + + return memoryDataSource; + }); - - // cancel the old save timer if present - // (this is equivalent to restarting the timer) - TimerTask oldTask = this.saveTimerTasksBySectionPos.put(dataSourcePos, timerTask); - if (oldTask != null) - { - oldTask.cancel(); - } - - return memoryDataSource; - }); - - return future; + return future; + } } public int getUnsavedCount() { return this.dataSourceByPosition.size(); } @@ -142,7 +179,7 @@ public class DelayedFullDataSourceSaveCache public interface ISaveDataSourceFunc { /** called after the timeout expires */ - void save(FullDataSourceV2 inputDataSource); + CompletableFuture saveAsync(FullDataSourceV2 inputDataSource); } } diff --git a/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/FullDataSourceProviderV2.java b/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/FullDataSourceProviderV2.java index 83e62601f..085bfbcd0 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/FullDataSourceProviderV2.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/FullDataSourceProviderV2.java @@ -453,14 +453,7 @@ public class FullDataSourceProviderV2 { // after the update finishes the legacy data source can be safely deleted this.legacyFileHandler.repo.deleteWithKey(legacyDataSource.getPos()); - - try - { - newDataSource.close(); - } - catch (Exception ignore) - { - } + newDataSource.close(); }); } catch (Exception e) @@ -626,13 +619,6 @@ public class FullDataSourceProviderV2 /** Can be used to display how many total chunk retrieval requests should be available. */ public void setEstimatedRemainingRetrievalChunkCount(int newCount) { } - /** - * Returns how many data sources are currently in memory and haven't - * been saved to the database. - * Returns -1 if this provider never stores data sources to memory. - */ - public int getUnsavedDataSourceCount() { return -1; } - public boolean fileExists(long pos) { return this.repo.getDataSizeInBytes(pos) > 0; } diff --git a/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/GeneratedFullDataSourceProvider.java b/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/GeneratedFullDataSourceProvider.java index 4bb2c8cc9..21fc3595b 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/GeneratedFullDataSourceProvider.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/GeneratedFullDataSourceProvider.java @@ -44,7 +44,6 @@ import org.apache.logging.log4j.Logger; import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.Nullable; -import java.awt.*; import java.io.File; import java.util.*; import java.util.concurrent.*; @@ -71,8 +70,6 @@ public class GeneratedFullDataSourceProvider extends FullDataSourceProviderV2 im private final AtomicReference worldGenQueueRef = new AtomicReference<>(null); private final ArrayList onWorldGenTaskCompleteListeners = new ArrayList<>(); - protected final DelayedFullDataSourceSaveCache delayedFullDataSourceSaveCache = new DelayedFullDataSourceSaveCache(this::onDataSourceSave, 5_000); - //=============// @@ -214,17 +211,6 @@ public class GeneratedFullDataSourceProvider extends FullDataSourceProviderV2 im int maxQueueCount = MAX_WORLD_GEN_REQUESTS_PER_THREAD * Config.Common.MultiThreading.numberOfThreads.get(); - if (this.delayedFullDataSourceSaveCache.getUnsavedCount() >= maxQueueCount) - { - // flushing since we're waiting for this timer to expire anyway - this.delayedFullDataSourceSaveCache.flush(); - - // don't queue additional world gen requests if there are - // a lot of data sources in memory - // (this is done to prevent infinite memory growth) - return false; - } - int availableTaskSlots = maxQueueCount - worldGenQueue.getWaitingTaskCount(); if (availableTaskSlots <= 0) { @@ -287,9 +273,6 @@ public class GeneratedFullDataSourceProvider extends FullDataSourceProviderV2 im @Override public void clearRetrievalQueue() { this.worldGenQueueRef.set(null); } - @Override - public int getUnsavedDataSourceCount() { return this.delayedFullDataSourceSaveCache.getUnsavedCount(); } - public boolean isFullyGenerated(ByteArrayList columnGenerationSteps) { @@ -413,22 +396,6 @@ public class GeneratedFullDataSourceProvider extends FullDataSourceProviderV2 im - //=======// - // debug // - //=======// - - @Override - public void debugRender(DebugRenderer renderer) - { - super.debugRender(renderer); - - this.delayedFullDataSourceSaveCache.dataSourceByPosition - .forEach((pos, dataSource) -> { renderer.renderBox(new DebugRenderer.Box(pos, -32f, 80f, 0.20f, Color.green.darker())); }); - } - - - - //================// // helper classes // //================// @@ -447,7 +414,7 @@ public class GeneratedFullDataSourceProvider extends FullDataSourceProviderV2 im { return (dataSource) -> { - GeneratedFullDataSourceProvider.this.delayedFullDataSourceSaveCache.writeDataSourceToMemoryAndQueueSave(dataSource); + GeneratedFullDataSourceProvider.this.onDataSourceSave(dataSource); }; } @@ -459,7 +426,7 @@ public class GeneratedFullDataSourceProvider extends FullDataSourceProviderV2 im // allows us to reduce cross-chunk lighting issues by lighting the whole 4x4 LOD at once DhLightingEngine.INSTANCE.bakeDataSourceSkyLight(fullDataSource, LodUtil.MAX_MC_LIGHT); - GeneratedFullDataSourceProvider.this.updateDataSourceAsync(fullDataSource); + this.updateDataSource(fullDataSource); } diff --git a/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/RemoteFullDataSourceProvider.java b/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/RemoteFullDataSourceProvider.java index a6320480d..bae918b48 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/RemoteFullDataSourceProvider.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/file/fullDatafile/RemoteFullDataSourceProvider.java @@ -99,7 +99,7 @@ public class RemoteFullDataSourceProvider extends GeneratedFullDataSourceProvide Long timestamp = this.getTimestampForPos(pos); if (timestamp != null) { - this.syncOnLoadRequestQueue.submitRequest(pos, timestamp, this.delayedFullDataSourceSaveCache::writeDataSourceToMemoryAndQueueSave); + this.syncOnLoadRequestQueue.submitRequest(pos, timestamp, this::updateDataSource); } return super.get(pos); diff --git a/core/src/main/java/com/seibel/distanthorizons/core/level/AbstractDhLevel.java b/core/src/main/java/com/seibel/distanthorizons/core/level/AbstractDhLevel.java index 684059aa6..345ab2c34 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/level/AbstractDhLevel.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/level/AbstractDhLevel.java @@ -59,8 +59,7 @@ public abstract class AbstractDhLevel implements IDhLevel @Nullable public BeaconBeamRepo beaconBeamRepo; - protected final DelayedFullDataSourceSaveCache delayedFullDataSourceSaveCache = new DelayedFullDataSourceSaveCache(this::onDataSourceSave, 500); - /** contains the {@link DhChunkPos} for each {@link DhSectionPos} that are queued to save via {@link AbstractDhLevel#delayedFullDataSourceSaveCache} */ + /** contains the {@link DhChunkPos} for each {@link DhSectionPos} that are queued to save */ protected final ConcurrentHashMap> updatedChunkPosSetBySectionPos = new ConcurrentHashMap<>(); protected final ConcurrentHashMap updatedChunkHashesByChunkPos = new ConcurrentHashMap<>(); @@ -141,39 +140,37 @@ public abstract class AbstractDhLevel implements IDhLevel // default methods // //=================// - @Override - public int getUnsavedDataSourceCount() { return this.delayedFullDataSourceSaveCache.getUnsavedCount(); } - @Override public CompletableFuture updateChunkAsync(IChunkWrapper chunkWrapper, int chunkHash) { - // data source synchronously written to memory so it can be safely closed - try (FullDataSourceV2 dataSource = FullDataSourceV2.createFromChunk(chunkWrapper)) + FullDataSourceV2 dataSource = FullDataSourceV2.createFromChunk(chunkWrapper); + if (dataSource == null) { - if (dataSource == null) - { - // This can happen if, among other reasons, a chunk save is superseded by a later event - return CompletableFuture.completedFuture(null); - } - - - this.updatedChunkPosSetBySectionPos.compute(dataSource.getPos(), (dataSourcePos, chunkPosSet) -> - { - if (chunkPosSet == null) - { - chunkPosSet = new HashSet<>(); - } - chunkPosSet.add(chunkWrapper.getChunkPos()); - return chunkPosSet; - }); - this.updatedChunkHashesByChunkPos.put(chunkWrapper.getChunkPos(), chunkHash); - - // batch updates to reduce overhead when flying around or breaking/placing a lot of blocks in an area - return this.delayedFullDataSourceSaveCache.writeDataSourceToMemoryAndQueueSave(dataSource); + // This can happen if, among other reasons, a chunk save is superseded by a later event + return CompletableFuture.completedFuture(null); } + + + this.updatedChunkPosSetBySectionPos.compute(dataSource.getPos(), (dataSourcePos, chunkPosSet) -> + { + if (chunkPosSet == null) + { + chunkPosSet = new HashSet<>(); + } + chunkPosSet.add(chunkWrapper.getChunkPos()); + return chunkPosSet; + }); + this.updatedChunkHashesByChunkPos.put(chunkWrapper.getChunkPos(), chunkHash); + + return this.onDataSourceSaveAsync(dataSource) + .handle((voidObj, throwable) -> + { + dataSource.close(); + return null; + }); } - private void onDataSourceSave(FullDataSourceV2 fullDataSource) + private CompletableFuture onDataSourceSaveAsync(FullDataSourceV2 fullDataSource) { // block lights should have been populated at the chunkWrapper stage // waiting to populate the data source's skylight at this stage prevents re-lighting and @@ -181,7 +178,8 @@ public abstract class AbstractDhLevel implements IDhLevel DhLightingEngine.INSTANCE.bakeDataSourceSkyLight(fullDataSource, this.hasSkyLight() ? LodUtil.MAX_MC_LIGHT : LodUtil.MIN_MC_LIGHT); - this.updateDataSourcesAsync(fullDataSource).thenRun(() -> + return this.updateDataSourcesAsync(fullDataSource) + .thenRun(() -> { HashSet updatedChunkPosSet = this.updatedChunkPosSetBySectionPos.remove(fullDataSource.getPos()); if (updatedChunkPosSet != null) diff --git a/core/src/main/java/com/seibel/distanthorizons/core/level/AbstractDhServerLevel.java b/core/src/main/java/com/seibel/distanthorizons/core/level/AbstractDhServerLevel.java index 19814f132..b91899535 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/level/AbstractDhServerLevel.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/level/AbstractDhServerLevel.java @@ -277,7 +277,7 @@ public abstract class AbstractDhServerLevel extends AbstractDhLevel implements I } } } - }); + }); } diff --git a/core/src/main/java/com/seibel/distanthorizons/core/level/IDhLevel.java b/core/src/main/java/com/seibel/distanthorizons/core/level/IDhLevel.java index 01dd069a8..dc354ee81 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/level/IDhLevel.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/level/IDhLevel.java @@ -62,12 +62,6 @@ public interface IDhLevel extends AutoCloseable, GeneratedFullDataSourceProvider CompletableFuture updateDataSourcesAsync(FullDataSourceV2 data); - /** - * this number is generally related to how many data sources have been updated - * due to chunk modifications or loads. - */ - int getUnsavedDataSourceCount(); - void addDebugMenuStringsToList(List messageList); /** diff --git a/core/src/main/java/com/seibel/distanthorizons/core/pooling/PhantomArrayListCheckout.java b/core/src/main/java/com/seibel/distanthorizons/core/pooling/PhantomArrayListCheckout.java index e0ceba276..6649d31c9 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/pooling/PhantomArrayListCheckout.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/pooling/PhantomArrayListCheckout.java @@ -1,9 +1,11 @@ package com.seibel.distanthorizons.core.pooling; import com.seibel.distanthorizons.core.util.ListUtil; +import com.seibel.distanthorizons.coreapi.util.StringUtil; import it.unimi.dsi.fastutil.bytes.ByteArrayList; import it.unimi.dsi.fastutil.longs.LongArrayList; import it.unimi.dsi.fastutil.shorts.ShortArrayList; +import org.jetbrains.annotations.Nullable; import java.lang.ref.SoftReference; import java.util.ArrayList; @@ -19,6 +21,9 @@ public class PhantomArrayListCheckout implements AutoCloseable { /** defines which pool the arrays should be returned too */ private final PhantomArrayListPool owningPool; + /** Will be null if the parent pool doesn't want leak stack tracing */ + @Nullable + public final String allocationStackTrace; private final ArrayList byteArrayLists = new ArrayList<>(); private final ArrayList shortArrayLists = new ArrayList<>(); @@ -33,6 +38,17 @@ public class PhantomArrayListCheckout implements AutoCloseable public PhantomArrayListCheckout(PhantomArrayListPool owningPool) { + if (owningPool.logGarbageCollectedStacks) + { + // TODO remove the top 4 or so lines since those will always be the same (relating to the phantom allocations) + // and aren't helpful when debugging + this.allocationStackTrace = StringUtil.join("\n", Thread.currentThread().getStackTrace()); + } + else + { + this.allocationStackTrace = null; + } + this.owningPool = owningPool; } diff --git a/core/src/main/java/com/seibel/distanthorizons/core/pooling/PhantomArrayListPool.java b/core/src/main/java/com/seibel/distanthorizons/core/pooling/PhantomArrayListPool.java index e17fd16b5..4479aebe6 100644 --- a/core/src/main/java/com/seibel/distanthorizons/core/pooling/PhantomArrayListPool.java +++ b/core/src/main/java/com/seibel/distanthorizons/core/pooling/PhantomArrayListPool.java @@ -6,6 +6,8 @@ import com.seibel.distanthorizons.core.logging.DhLoggerBuilder; import com.seibel.distanthorizons.core.logging.f3.F3Screen; import com.seibel.distanthorizons.core.util.LodUtil; import com.seibel.distanthorizons.core.util.ThreadUtil; +import com.seibel.distanthorizons.core.util.objects.Pair; +import com.seibel.distanthorizons.coreapi.ModInfo; import com.seibel.distanthorizons.coreapi.util.StringUtil; import it.unimi.dsi.fastutil.bytes.ByteArrayList; import it.unimi.dsi.fastutil.longs.LongArrayList; @@ -50,15 +52,17 @@ public class PhantomArrayListPool private static final Logger LOGGER = DhLoggerBuilder.getLogger(); /** - * the recycler thread needs to be triggered relatively often to prevent + * the recycler thread needs to be triggered relatively frequently to prevent * build up of GC'ed arrays. + * However, some JVM's will wait a while before collecting lost objects, + * so in general it is still much better to use the try-finally. */ - private static final int PHANTOM_REF_CHECK_TIME_IN_MS = 1_000; + private static final int PHANTOM_REF_CHECK_TIME_IN_MS = 5_000; private static final ThreadPoolExecutor RECYCLER_THREAD = ThreadUtil.makeSingleDaemonThreadPool("Phantom Array Recycler"); private static final ArrayList POOL_LIST = new ArrayList<>(); /** if enabled the number of GC'ed arrays will be logged */ - private static final boolean LOG_ARRAY_RECOVERY = false; + private static final boolean LOG_ARRAY_RECOVERY = ModInfo.IS_DEV_BUILD; private static boolean lowMemoryWarningLogged = false; @@ -67,6 +71,12 @@ public class PhantomArrayListPool /** used for debugging and tracking what the pool contains */ public final String name; + /** + * Getting stack traces is very slow. + * If we know which pool is leaking objects we can enable tracking for that specific + * pool and prevent slow-downs in other pools. + */ + public final boolean logGarbageCollectedStacks; public final ConcurrentHashMap, PhantomArrayListCheckout> phantomRefToCheckout = new ConcurrentHashMap<>(); @@ -74,7 +84,6 @@ public class PhantomArrayListPool - private final ConcurrentLinkedQueue pooledByteArrays = new ConcurrentLinkedQueue<>(); private final ConcurrentLinkedQueue pooledShortArrays = new ConcurrentLinkedQueue<>(); private final ConcurrentLinkedQueue> pooledLongArrays = new ConcurrentLinkedQueue<>(); @@ -98,89 +107,27 @@ public class PhantomArrayListPool - //=============// - // constructor // - //=============// + //==============// + // constructors // + //==============// // shared setup used by all pools static { RECYCLER_THREAD.execute(() -> runPhantomReferenceCleanupLoop()); } - private static void runPhantomReferenceCleanupLoop() - { - while (true) - { - try - { - try - { - Thread.sleep(PHANTOM_REF_CHECK_TIME_IN_MS); - } - catch (InterruptedException ignore) { } - - - for (int i = 0; i < POOL_LIST.size(); i++) - { - PhantomArrayListPool pool = POOL_LIST.get(i); - - int returnedByteArrayCount = 0; - int returnedShortArrayCount = 0; - int returnedLongArrayCount = 0; - Reference phantomRef = pool.phantomRefQueue.poll(); - while (phantomRef != null) - { - // return the pooled arrays - PhantomArrayListCheckout checkout = pool.phantomRefToCheckout.remove(phantomRef); - if (checkout != null) - { - returnedByteArrayCount += checkout.getByteArrayCount(); - returnedShortArrayCount += checkout.getShortArrayCount(); - returnedLongArrayCount += checkout.getLongArrayCount(); - pool.returnCheckout(checkout); - } - else - { - // shouldn't happen, but just in case - LOGGER.warn("Pool: ["+pool.name+"]. Unable to find checkout for phantom reference ["+phantomRef+"], arrays will need to be recreated."); - } - - phantomRef = pool.phantomRefQueue.poll(); - } - - if (LOG_ARRAY_RECOVERY) - { - if (returnedByteArrayCount != 0 - && returnedShortArrayCount != 0 - && returnedLongArrayCount != 0) - { - // we only want to log when arrays have been returned - LOGGER.info("Pool: ["+pool.name+"]. Returned byte:["+F3Screen.NUMBER_FORMAT.format(returnedByteArrayCount)+"], short:["+F3Screen.NUMBER_FORMAT.format(returnedShortArrayCount)+"], long:["+F3Screen.NUMBER_FORMAT.format(returnedLongArrayCount)+"]."); - } - } - - // since this is just for debugging it only needs to be recalculated once in a while - pool.recalculateSizeForDebugging(); - } - } - catch (Exception e) - { - LOGGER.error("Unexpected error in phantom pool return thread, error: [" + e.getMessage() + "].", e); - } - } - } - public PhantomArrayListPool(String name) + public PhantomArrayListPool(String name) { this(name, false); } + public PhantomArrayListPool(String name, boolean logGarbageCollectedStacks) { POOL_LIST.add(this); this.name = name; + this.logGarbageCollectedStacks = logGarbageCollectedStacks; } - - //==============// // get checkout // //==============// @@ -323,6 +270,137 @@ public class PhantomArrayListPool + //==================// + // phantom recovery // + //==================// + + private static void runPhantomReferenceCleanupLoop() + { + while (true) + { + // these arrays are stored here so they don't have to be re-allocated each loop + ArrayList> allocationStackTraceCountPairList = new ArrayList<>(); + + try + { + try + { + Thread.sleep(PHANTOM_REF_CHECK_TIME_IN_MS); + } + catch (InterruptedException ignore) { } + + + for (int poolIndex = 0; poolIndex < POOL_LIST.size(); poolIndex++) + { + PhantomArrayListPool pool = POOL_LIST.get(poolIndex); + + int returnedByteArrayCount = 0; + int returnedShortArrayCount = 0; + int returnedLongArrayCount = 0; + int checkoutCount = 0; + + allocationStackTraceCountPairList.clear(); + + Reference phantomRef = pool.phantomRefQueue.poll(); + while (phantomRef != null) + { + // return the pooled arrays + PhantomArrayListCheckout checkout = pool.phantomRefToCheckout.remove(phantomRef); + if (checkout != null) + { + returnedByteArrayCount += checkout.getByteArrayCount(); + returnedShortArrayCount += checkout.getShortArrayCount(); + returnedLongArrayCount += checkout.getLongArrayCount(); + checkoutCount++; + pool.returnCheckout(checkout); + + if (pool.logGarbageCollectedStacks + && checkout.allocationStackTrace != null) // stack trace shouldn't be null, but just in case + { + putAndIncrementTrackingString(checkout.allocationStackTrace, allocationStackTraceCountPairList); + } + } + else + { + // shouldn't happen, but just in case + LOGGER.warn("Pool: ["+pool.name+"]. Unable to find checkout for phantom reference ["+phantomRef+"], arrays will need to be recreated."); + } + + phantomRef = pool.phantomRefQueue.poll(); + } + + if (LOG_ARRAY_RECOVERY || pool.logGarbageCollectedStacks) + { + // we only want to log when something has been returned + if (checkoutCount != 0 + || returnedByteArrayCount != 0 + || returnedShortArrayCount != 0 + || returnedLongArrayCount != 0) + { + LOGGER.warn("Pool: ["+ pool.name+"] phantom recovery. Returned checkouts:["+F3Screen.NUMBER_FORMAT.format(checkoutCount)+"], byte:["+F3Screen.NUMBER_FORMAT.format(returnedByteArrayCount)+"], short:["+F3Screen.NUMBER_FORMAT.format(returnedShortArrayCount)+"], long:["+F3Screen.NUMBER_FORMAT.format(returnedLongArrayCount)+"]."); + + // log stack traces if present + if (pool.logGarbageCollectedStacks) + { + // high numbers first + allocationStackTraceCountPairList.sort((a, b) -> Integer.compare(b.second.get(), a.second.get())); + + StringBuilder stringBuilder = new StringBuilder(); + for (int j = 0; j < allocationStackTraceCountPairList.size(); j++) + { + int count = allocationStackTraceCountPairList.get(j).second.get(); + String stack = allocationStackTraceCountPairList.get(j).first; + + stringBuilder.append(count).append(". ").append(stack).append("\n"); + } + LOGGER.warn("Stacks: ["+ allocationStackTraceCountPairList.size()+"]\n" + stringBuilder.toString()); + } + } + } + + // since this is just for debugging it only needs to be recalculated once in a while + pool.recalculateSizeForDebugging(); + } + } + catch (Exception e) + { + LOGGER.error("Unexpected error in phantom pool return thread, error: [" + e.getMessage() + "].", e); + } + } + } + /** + * This was separated out so it could be used for other string pair lists. + * James originally had an idea to add a shorter static string + * ID to each allocated {@link PhantomArrayListCheckout} as a simpler version of the stack trace, + * however it became a bit more difficult and messy than he wanted to deal with, so for now we just + * have the stack trace. + */ + private static void putAndIncrementTrackingString( + String key, + ArrayList> allocationStackTraceCountPairList) + { + // sequential search, for the number of elements we're dealing with (less than 20) + // this should be sufficiently fast + boolean pairFound = false; + for (int i = 0; i < allocationStackTraceCountPairList.size(); i++) + { + Pair possiblePair = allocationStackTraceCountPairList.get(i); + if (possiblePair.first.equals(key)) + { + possiblePair.second.getAndIncrement(); + pairFound = true; + break; + } + } + + if (!pairFound) + { + allocationStackTraceCountPairList.add(new Pair<>(key, new AtomicInteger(1))); + } + } + + + //=================// // return checkout // //=================//