From 2668c279c79d3cc98b1fce5f5b558fe777cdf904 Mon Sep 17 00:00:00 2001 From: LemADEC Date: Thu, 18 Mar 2021 23:46:05 +0100 Subject: [PATCH] Improved logs related to chunk reloading issues --- .../warpdrive/block/TileEntityAbstractBase.java | 11 ++++++++++- .../warpdrive/block/TileEntityAbstractMachine.java | 8 ++++++++ .../java/cr0s/warpdrive/config/WarpDriveConfig.java | 2 ++ src/main/java/cr0s/warpdrive/data/ChunkData.java | 13 ++++++++----- .../java/cr0s/warpdrive/event/ChunkHandler.java | 6 +++--- 5 files changed, 31 insertions(+), 9 deletions(-) diff --git a/src/main/java/cr0s/warpdrive/block/TileEntityAbstractBase.java b/src/main/java/cr0s/warpdrive/block/TileEntityAbstractBase.java index c2c0e69c..1841c417 100644 --- a/src/main/java/cr0s/warpdrive/block/TileEntityAbstractBase.java +++ b/src/main/java/cr0s/warpdrive/block/TileEntityAbstractBase.java @@ -77,6 +77,13 @@ public abstract class TileEntityAbstractBase extends TileEntity implements IBloc return; } + if (WarpDrive.isDev && this instanceof TileEntityAbstractMachine) { + WarpDrive.logger.info(String.format("%s onConstructed at %d", this, world.getWorldTime())); + if (Commons.throttleMe("onConstructed")) { + new Exception().printStackTrace(WarpDrive.printStreamInfo); + } + } + // immediately retrieve tier, we need it to connect energy conduits and save the world before the first tick final Block block = getBlockType(); if (block instanceof IBlockBase) { @@ -285,7 +292,9 @@ public abstract class TileEntityAbstractBase extends TileEntity implements IBloc onConstructed(); WarpDrive.logger.error(String.format("%s Tile entity was used before being loaded! this is a forge issue.", this )); - new RuntimeException().printStackTrace(WarpDrive.printStreamError); + if (Commons.throttleMe("TileEntityAbstractBase.getTierIndex")) { + new RuntimeException().printStackTrace(WarpDrive.printStreamInfo); + } } return enumTier.getIndex(); } diff --git a/src/main/java/cr0s/warpdrive/block/TileEntityAbstractMachine.java b/src/main/java/cr0s/warpdrive/block/TileEntityAbstractMachine.java index 994539b2..d0b6a95a 100644 --- a/src/main/java/cr0s/warpdrive/block/TileEntityAbstractMachine.java +++ b/src/main/java/cr0s/warpdrive/block/TileEntityAbstractMachine.java @@ -115,6 +115,14 @@ public abstract class TileEntityAbstractMachine extends TileEntityAbstractInterf } public void markDirtyAssembly() { + + if (WarpDrive.isDev) { + WarpDrive.logger.info(String.format("%s markDirtyAssembly at %d", this, world.getWorldTime())); + if (Commons.throttleMe("markDirtyAssembly")) { + new Exception().printStackTrace(WarpDrive.printStreamInfo); + } + } + isDirtyAssembly = true; } diff --git a/src/main/java/cr0s/warpdrive/config/WarpDriveConfig.java b/src/main/java/cr0s/warpdrive/config/WarpDriveConfig.java index 2a972971..c46185a7 100644 --- a/src/main/java/cr0s/warpdrive/config/WarpDriveConfig.java +++ b/src/main/java/cr0s/warpdrive/config/WarpDriveConfig.java @@ -259,6 +259,7 @@ public class WarpDriveConfig { public static boolean LOGGING_XML_PREPROCESSOR = false; public static boolean LOGGING_RENDERING = false; public static boolean LOGGING_CHUNK_HANDLER = false; + public static boolean LOGGING_CHUNK_RELOADING = true; public static boolean LOGGING_CHUNK_LOADING = true; public static boolean LOGGING_ENTITY_FX = false; public static boolean LOGGING_CLIENT_SYNCHRONIZATION = false; @@ -992,6 +993,7 @@ public class WarpDriveConfig { LOGGING_XML_PREPROCESSOR = config.get("logging", "enable_XML_preprocessor_logs", LOGGING_XML_PREPROCESSOR, "Save XML preprocessor results as output*.xml file, enable it to debug your XML configuration files").getBoolean(false); LOGGING_RENDERING = config.get("logging", "enable_rendering_logs", LOGGING_RENDERING, "Detailed rendering logs to help debug the mod.").getBoolean(false); LOGGING_CHUNK_HANDLER = config.get("logging", "enable_chunk_handler_logs", LOGGING_CHUNK_HANDLER, "Detailed chunk data logs to help debug the mod.").getBoolean(false); + LOGGING_CHUNK_RELOADING = config.get("logging", "enable_chunk_reloading_logs", LOGGING_CHUNK_RELOADING, "Report in logs when a chunk is reloaded shortly after being unloaded, usually associated with server lag.").getBoolean(false); LOGGING_CHUNK_LOADING = config.get("logging", "enable_chunk_loading_logs", LOGGING_CHUNK_LOADING, "Chunk loading logs, enable it to report chunk loaders updates").getBoolean(false); LOGGING_ENTITY_FX = config.get("logging", "enable_entity_fx_logs", LOGGING_ENTITY_FX, "EntityFX logs, enable it to dump entityFX registry updates").getBoolean(false); LOGGING_GRAVITY = config.get("logging", "enable_gravity_logs", LOGGING_GRAVITY, "Gravity logs, enable it before reporting fall damage and related issues").getBoolean(false); diff --git a/src/main/java/cr0s/warpdrive/data/ChunkData.java b/src/main/java/cr0s/warpdrive/data/ChunkData.java index 96a084a2..4ae6586f 100644 --- a/src/main/java/cr0s/warpdrive/data/ChunkData.java +++ b/src/main/java/cr0s/warpdrive/data/ChunkData.java @@ -25,7 +25,7 @@ public class ChunkData { private static final String TAG_AIR_SEGMENT_DATA = "data"; private static final String TAG_AIR_SEGMENT_DELAY = "delay"; private static final String TAG_AIR_SEGMENT_Y = "y"; - private static final long RELOAD_DELAY_MIN_MS = 100; + private static final long RELOAD_DELAY_MIN_MS = 10000; private static final long LOAD_UNLOAD_DELAY_MIN_MS = 1000; private static final long SAVE_SAVE_DELAY_MIN_MS = 100; @@ -54,19 +54,22 @@ public class ChunkData { timeUnloaded = 0L; } - public void load(final NBTTagCompound tagCompoundChunk) { + public void load(@Nonnull final NBTTagCompound tagCompoundChunk, @Nonnull final World world) { // check consistency assert !isLoaded; // detects fast reloading final long time = System.currentTimeMillis(); - if ( WarpDriveConfig.LOGGING_CHUNK_HANDLER + if ( WarpDriveConfig.LOGGING_CHUNK_RELOADING && timeUnloaded != 0L && time - timeUnloaded < RELOAD_DELAY_MIN_MS ) { - WarpDrive.logger.warn(String.format("Chunk %s (%d %d %d) is reloading after only %d ms", + WarpDrive.logger.warn(String.format("Chunk %s %s is reloading after only %d ms", chunkCoordIntPair, - getChunkPosition().getX(), getChunkPosition().getY(), getChunkPosition().getZ(), + Commons.format(world, getChunkPosition()), time - timeUnloaded)); + if (Commons.throttleMe("ChunkData.ChunkReloading")) { + new RuntimeException().printStackTrace(WarpDrive.printStreamInfo); + } } // load defaults diff --git a/src/main/java/cr0s/warpdrive/event/ChunkHandler.java b/src/main/java/cr0s/warpdrive/event/ChunkHandler.java index 472ac3a0..de4875e9 100644 --- a/src/main/java/cr0s/warpdrive/event/ChunkHandler.java +++ b/src/main/java/cr0s/warpdrive/event/ChunkHandler.java @@ -91,7 +91,7 @@ public class ChunkHandler { assert chunkData != null; // (world can load a non-generated chunk, or the chunk be regenerated, so we reset only as needed) if (!chunkData.isLoaded()) { - chunkData.load(new NBTTagCompound()); + chunkData.load(new NBTTagCompound(), world); } } @@ -107,7 +107,7 @@ public class ChunkHandler { final ChunkData chunkData = getChunkData(event.getWorld().isRemote, event.getWorld().provider.getDimension(), event.getChunk().x, event.getChunk().z, true); assert chunkData != null; - chunkData.load(event.getData()); + chunkData.load(event.getData(), event.getWorld()); } // (called after data loading, or before a late generation, or on client side) @@ -123,7 +123,7 @@ public class ChunkHandler { final ChunkData chunkData = getChunkData(event.getWorld().isRemote, event.getWorld().provider.getDimension(), event.getChunk().x, event.getChunk().z, true); assert chunkData != null; if (!chunkData.isLoaded()) { - chunkData.load(new NBTTagCompound()); + chunkData.load(new NBTTagCompound(), event.getWorld()); } } /*