Astral Sorcery

Astral Sorcery

63M Downloads

Server crash loop detecting block changes

bluelightning32 opened this issue ยท 3 comments

commented

I'm filing this issue to track what I found in case it reproduces again for me or someone else. I don't think this issue is actionable for AS devs at this point. So feel free to close it.

I recently upgraded my servers to Enigmatica Expert 1.54, but with spongeforge-1.12.2-2768-7.1.6-RC3557 and astralsorcery-1.12.2-1.10.11. I have 3 such servers. After the a scheduled reboot, on of my servers started crash looping.

Here's the main part of the crash (full report here):

java.lang.AbstractMethodError: Method com/rwtema/extrautils2/tile/TilePower$1.func_185929_b(Ljava/lang/String;)Lcom/google/common/base/Optional; is abstract
	at com.rwtema.extrautils2.tile.TilePower$1.func_185929_b(TilePower.java)
	at hellfirepvp.astralsorcery.common.util.nbt.NBTHelper.getBlockStateFromTag(NBTHelper.java:153)
	at hellfirepvp.astralsorcery.common.structure.change.BlockStateChangeSet.readFromNBT(BlockStateChangeSet.java:68)
	at hellfirepvp.astralsorcery.common.structure.change.ChangeSubscriber.readFromNBT(ChangeSubscriber.java:88)
	at hellfirepvp.astralsorcery.common.data.world.data.StructureMatchingBuffer.readFromNBT(StructureMatchingBuffer.java:130)
	at hellfirepvp.astralsorcery.common.data.world.WorldCacheManager.attemptLoad(WorldCacheManager.java:180)
	at hellfirepvp.astralsorcery.common.data.world.WorldCacheManager.loadDataFromFile(WorldCacheManager.java:122)
	at hellfirepvp.astralsorcery.common.data.world.WorldCacheManager.loadAndCache(WorldCacheManager.java:97)
	at hellfirepvp.astralsorcery.common.data.world.WorldCacheManager.getOrLoadData(WorldCacheManager.java:54)
	at hellfirepvp.astralsorcery.common.util.PatternMatchHelper.getOrCreateMatcher(PatternMatchHelper.java:31)
	at hellfirepvp.astralsorcery.common.tile.TileCelestialGateway.updateMultiblockState(TileCelestialGateway.java:133)
	at hellfirepvp.astralsorcery.common.tile.TileCelestialGateway.func_73660_a(TileCelestialGateway.java:70)
	at org.spongepowered.common.event.tracking.TrackingUtil.tickTileEntity(TrackingUtil.java:228)

I added extra logging to diagnose the problem:

diff --git a/src/main/java/hellfirepvp/astralsorcery/common/structure/change/BlockStateChangeSet.java b/src/main/java/hellfirepvp/astralsorcery/common/structure/change/BlockStateChangeSet.java
index b6061914..e9d65eb4 100644
--- a/src/main/java/hellfirepvp/astralsorcery/common/structure/change/BlockStateChangeSet.java
+++ b/src/main/java/hellfirepvp/astralsorcery/common/structure/change/BlockStateChangeSet.java
@@ -8,6 +8,7 @@
 
 package hellfirepvp.astralsorcery.common.structure.change;
 
+import hellfirepvp.astralsorcery.AstralSorcery;
 import com.google.common.collect.Maps;
 import hellfirepvp.astralsorcery.common.util.nbt.NBTHelper;
 import net.minecraft.block.state.IBlockState;
@@ -65,6 +66,7 @@ public final class BlockStateChangeSet {
             NBTTagCompound changeTag = changeList.getCompoundTagAt(i);
 
             BlockPos pos = NBTHelper.readBlockPosFromNBT(changeTag);
+            AstralSorcery.log.info("pos=" + pos.getX() + "," + pos.getY() + "," + pos.getZ());
             IBlockState oldState = NBTHelper.getBlockStateFromTag(changeTag.getCompoundTag("oldState"),
                     Blocks.AIR.getDefaultState());
             IBlockState newState = NBTHelper.getBlockStateFromTag(changeTag.getCompoundTag("newState"),
diff --git a/src/main/java/hellfirepvp/astralsorcery/common/util/nbt/NBTHelper.java b/src/main/java/hellfirepvp/astralsorcery/common/util/nbt/NBTHelper.java
index 9d8c2604..ddd6ac41 100644
--- a/src/main/java/hellfirepvp/astralsorcery/common/util/nbt/NBTHelper.java
+++ b/src/main/java/hellfirepvp/astralsorcery/common/util/nbt/NBTHelper.java
@@ -137,8 +137,14 @@ public class NBTHelper {
 
     @Nullable
     public static <T extends Comparable<T>> IBlockState getBlockStateFromTag(NBTTagCompound cmp, IBlockState _default) {
         ResourceLocation key = new ResourceLocation(cmp.getString("registryName"));
         Block block = ForgeRegistries.BLOCKS.getValue(key);
+        AstralSorcery.log.info("getBlockStateFromTag" + block + "  " + cmp.getString("registryName"));
         if(block == null || block == Blocks.AIR) return _default;
         IBlockState state = block.getDefaultState();
         Collection<IProperty<?>> properties = state.getPropertyKeys();
@@ -147,6 +153,7 @@ public class NBTHelper {
             NBTTagCompound propertyTag = list.getCompoundTagAt(i);
             String valueStr = propertyTag.getString("value");
             String propertyStr = propertyTag.getString("property");
+            AstralSorcery.log.info("valueStr=" + valueStr + " propertyStr=" + propertyStr);
             IProperty<T> match = (IProperty<T>) MiscUtils.iterativeSearch(properties, prop -> prop.getName().equalsIgnoreCase(propertyStr));
             if(match != null) {
                 try {

This is the result of the extra logging:

[21:28:45] [Server thread/INFO] [Astral Sorcery]: pos=2,1,-5
[21:28:45] [Server thread/INFO] [Astral Sorcery]: getBlockStateFromTagBlock{extrautils2:user}  extrautils2:user
[21:28:45] [Server thread/INFO] [Astral Sorcery]: valueStr=false propertyStr=active
[21:28:45] [Server thread/WARN] [enderio]: @Devs: See github for dev env setup; set INDEV if needed.
[21:28:45] [Server thread/ERROR] [net.minecraft.server.MinecraftServer]: Encountered an unexpected exception
net.minecraft.util.ReportedException: Ticking block entity

I temporarily changed the AS code to ignore changes from all extrautils2:user blocks. The server stopped crash looping. I went to the location at 520,69,712 as indicated by the crash report. There was no mechanical user there. I broke the celestial gateway and rebuilt it just to be safe. I switched AS back to the standard version (that does not ignore extrautils2:user blocks). The server did not crash.

My current structurematcher.dat does not include any extrautils2:user blocks. However, I unzipped a backup from around the time of the crash. It did include one at a different location:

     + 5 entries
     | + bposX: -1104
     | + bposY: 147
     | + bposZ: 1309
     | + identifier: astralsorcery:pattern_altar_t4
     | + matchData: 6 entries
     |   + isMatching: 0
     |   + bposX: -1104
     |   + bposY: 147
     |   + bposZ: 1309
...
     |   |   + 5 entries
     |   |   | + bposX: 2
     |   |   | + bposY: 1
     |   |   | + bposZ: -5
     |   |   | + newState: 2 entries
     |   |   | | + registryName: extrautils2:user
     |   |   | | + properties: 2 entries
     |   |   | |   + 2 entries
     |   |   | |   | + property: active
     |   |   | |   | + value: false
     |   |   | |   + 2 entries
     |   |   | |     + property: facing
     |   |   | |     + value: south
     |   |   | + oldState: 2 entries
     |   |   |   + registryName: extrautils2:user
     |   |   |   + properties: 2 entries
     |   |   |     + 2 entries
     |   |   |     | + property: active
     |   |   |     | + value: false
     |   |   |     + 2 entries
     |   |   |       + property: facing
     |   |   |       + value: south

I went to that location, and it does have a mechanical user:
image

I'm hoping that this crash is due to the change tracking getting very out of sync due to the changing tracking with SpongeForge bug, and now the change tracking is more in sync.

commented

java.lang.AbstractMethodError: Method com/rwtema/extrautils2/tile/TilePower$1.func_185929_b(Ljava/lang/String;)Lcom/google/common/base/Optional; is abstract

Nope, this error is due to Exu2. Talked about in #973 and more detailed in #977

commented

The crash loop happened again on the next scheduled server restart. extrautils2:user was in the structurematcher.dat file again.

I deleted the structurematcher.dat file, and the server started up.

commented

Doesn't change it is still an extra utilities 2 error.