Terra icon indicating copy to clipboard operation
Terra copied to clipboard

[Bug] Chunk gen NPE when resources are reloaded before safe stronghold data creation

Open Akiranya opened this issue 2 years ago • 32 comments

Pre-Issue Checklist

  • [x] I have checked that I am on the latest version of Terra.
  • [x] I have searched the github issue tracker for similar issues, including closed ones.
  • [x] I have made sure that this is not a bug with another mod or plugin, and it is Terra that is causing the issue.
  • [x] I have checked that this is an issue with Terra and not an issue with the pack I am using.
  • [x] I have attached a copy of the latest.log file
  • [x] I have filled out and provided all the appropriate information.

Environment

Name Value
Terra Version 6.1.2-BETA
Platform / Platform Version Current: git-Purpur-1684 (MC: 1.19)*
Any External Plugins or Mods AuctionHouse, BanItem, BetonQuest, Brewery, ChestSort, Chunky, Citizens, CitizensText, CommandAPI, ConditionalTextPlaceholders, CoreProtect, CraftBook, CrazyCrates, dynmap, Dynmap-Towny, Dynmap-WorldGuard, eco, EcoEnchants, Essentials, EssentialsChat, EssentialsSpawn, FarmControl, GemsEconomy, HeadDatabase, helper, helper-profiles, helper-sql, InventoryRollbackPlus, ItemsAdder, LangUtils, LevelledMobs, LocketteX, LoneLibs, LuckPerms, MMOExpansion, MMOItems, ModelEngine, MoeCore, MoeUtils, MultiChat*, Multiverse-Core, Multiverse-NetherPortals, MythicLib, MythicMobs, OpenInv, PlaceholderAPI, ProtocolLib, RandomTeleport (FUBSRandomTeleport), RPGInventory, ShowItem, SiegeWar, spark, TAB-Bridge, Terra, Towny, TownyChat, TownyFlight, Vault, VillagerMarket, VoidGen, WorldEdit, WorldGuard, WorldGuard-Towny
Terra Packs In Use [email protected]
Terra Addons In Use https://pastebin.com/942tMKdb

Issue Description

Hi, I'm new to Terra and I encountered some problem with Terra (really love this plugin). When generating terrain using the plugin Chunky or just moving around, the errors randomly appear. The config of Terra is all default. I searched in the discord and I found another user has the same issue as mine (https://discord.com/channels/715448651786485780/765260067812540416/990301360274669618)

Steps to reproduce

Create a new world using Terra and move around / use Chunky to generate the world. To better reproduce the error, restart the server and continue the chunk generation might help. Sometimes it does not appear but once appear the error is just so long...

Expected behavior

There should be no errors...

Actual behavior

When generating terrain using the plugin Chunky or just moving around, the errors randomly appear.

Updated 7/7/2022: Server crash log -> https://pastebin.com/6VHj33xq (sorry I forgot to put it here in the first place)

Full stacktrace

latest.log: https://pastebin.com/RRybGKv1

Exception Stacktrace
[17:35:15] [Worker-Main-1/ERROR]: Failed to schedule unload callback for chunk [-3, -17]
java.util.concurrent.CompletionException: net.minecraft.ReportedException: Exception generating new chunk
	at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:315) ~[?:?]
	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:320) ~[?:?]
	at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1159) ~[?:?]
	at java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:482) ~[?:?]
	at net.minecraft.server.level.ChunkTaskPriorityQueueSorter.lambda$message$1(ChunkTaskPriorityQueueSorter.java:51) ~[?:?]
	at net.minecraft.util.thread.ProcessorMailbox.pollTask(ProcessorMailbox.java:87) ~[?:?]
	at net.minecraft.util.thread.ProcessorMailbox.pollUntil(ProcessorMailbox.java:141) ~[?:?]
	at net.minecraft.util.thread.ProcessorMailbox.run(ProcessorMailbox.java:96) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
	at java.lang.Thread.run(Thread.java:833) ~[?:?]
Caused by: net.minecraft.ReportedException: Exception generating new chunk
	at net.minecraft.server.level.ChunkTracker.lambda$scheduleChunkGeneration$37(ChunkTracker.java:1305) ~[?:?]
	at com.mojang.datafixers.util.Either$Left.map(Either.java:38) ~[purpur-1.19.jar:?]
	at net.minecraft.server.level.ChunkTracker.lambda$scheduleChunkGeneration$39(ChunkTracker.java:1286) ~[?:?]
	at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150) ~[?:?]
	... 8 more
Caused by: java.lang.NullPointerException: Cannot invoke "com.dfsek.terra.api.util.generic.Lazy.value()" because the return value of "java.util.Map.get(Object)" is null
	at com.dfsek.terra.bukkit.nms.v1_19_R1.NMSChunkGeneratorDelegate.a(NMSChunkGeneratorDelegate.java:163) ~[Terra-bukkit-6.1.2-BETA.jar:?]
	at net.minecraft.world.level.levelgen.structure.placement.ConcentricRingsStructurePlacement.isPlacementChunk(ConcentricRingsStructurePlacement.java:62) ~[purpur-1.19.jar:git-Purpur-1684]
	at net.minecraft.world.level.levelgen.structure.placement.StructurePlacement.isStructureChunk(StructurePlacement.java:63) ~[purpur-1.19.jar:git-Purpur-1684]
	at net.minecraft.world.level.chunk.ChunkGenerator.lambda$createStructures$19(ChunkGenerator.java:771) ~[purpur-1.19.jar:git-Purpur-1684]
	at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[?:?]
	at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) ~[?:?]
	at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) ~[?:?]
	at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) ~[?:?]
	at java.util.AbstractList$RandomAccessSpliterator.forEachRemaining(AbstractList.java:720) ~[?:?]
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
	at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) ~[?:?]
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) ~[?:?]
	at net.minecraft.world.level.chunk.ChunkGenerator.createStructures(ChunkGenerator.java:756) ~[purpur-1.19.jar:git-Purpur-1684]
	at net.minecraft.world.level.chunk.ChunkStatus.lambda$static$2(ChunkStatus.java:51) ~[purpur-1.19.jar:git-Purpur-1684]
	at net.minecraft.world.level.chunk.ChunkStatus.generate(ChunkStatus.java:275) ~[purpur-1.19.jar:git-Purpur-1684]
	at net.minecraft.server.level.ChunkTracker.lambda$scheduleChunkGeneration$37(ChunkTracker.java:1288) ~[?:?]
	at com.mojang.datafixers.util.Either$Left.map(Either.java:38) ~[purpur-1.19.jar:?]
	at net.minecraft.server.level.ChunkTracker.lambda$scheduleChunkGeneration$39(ChunkTracker.java:1286) ~[?:?]
	at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150) ~[?:?]
	... 8 more
[17:35:15] [Worker-Main-1/ERROR]: Failed to schedule load callback for chunk [-3, -17]
java.util.concurrent.CompletionException: net.minecraft.ReportedException: Exception generating new chunk
	at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:315) ~[?:?]
	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:320) ~[?:?]
	at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1159) ~[?:?]
	at java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:482) ~[?:?]
	at net.minecraft.server.level.ChunkTaskPriorityQueueSorter.lambda$message$1(ChunkTaskPriorityQueueSorter.java:51) ~[?:?]
	at net.minecraft.util.thread.ProcessorMailbox.pollTask(ProcessorMailbox.java:87) ~[?:?]
	at net.minecraft.util.thread.ProcessorMailbox.pollUntil(ProcessorMailbox.java:141) ~[?:?]
	at net.minecraft.util.thread.ProcessorMailbox.run(ProcessorMailbox.java:96) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
	at java.lang.Thread.run(Thread.java:833) ~[?:?]
Caused by: net.minecraft.ReportedException: Exception generating new chunk
	at net.minecraft.server.level.ChunkTracker.lambda$scheduleChunkGeneration$37(ChunkTracker.java:1305) ~[?:?]
	at com.mojang.datafixers.util.Either$Left.map(Either.java:38) ~[purpur-1.19.jar:?]
	at net.minecraft.server.level.ChunkTracker.lambda$scheduleChunkGeneration$39(ChunkTracker.java:1286) ~[?:?]
	at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150) ~[?:?]
	... 8 more
Caused by: java.lang.NullPointerException: Cannot invoke "com.dfsek.terra.api.util.generic.Lazy.value()" because the return value of "java.util.Map.get(Object)" is null
	at com.dfsek.terra.bukkit.nms.v1_19_R1.NMSChunkGeneratorDelegate.a(NMSChunkGeneratorDelegate.java:163) ~[Terra-bukkit-6.1.2-BETA.jar:?]
	at net.minecraft.world.level.levelgen.structure.placement.ConcentricRingsStructurePlacement.isPlacementChunk(ConcentricRingsStructurePlacement.java:62) ~[purpur-1.19.jar:git-Purpur-1684]
	at net.minecraft.world.level.levelgen.structure.placement.StructurePlacement.isStructureChunk(StructurePlacement.java:63) ~[purpur-1.19.jar:git-Purpur-1684]
	at net.minecraft.world.level.chunk.ChunkGenerator.lambda$createStructures$19(ChunkGenerator.java:771) ~[purpur-1.19.jar:git-Purpur-1684]
	at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[?:?]
	at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) ~[?:?]
	at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) ~[?:?]
	at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) ~[?:?]
	at java.util.AbstractList$RandomAccessSpliterator.forEachRemaining(AbstractList.java:720) ~[?:?]
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
	at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) ~[?:?]
	at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) ~[?:?]
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) ~[?:?]
	at net.minecraft.world.level.chunk.ChunkGenerator.createStructures(ChunkGenerator.java:756) ~[purpur-1.19.jar:git-Purpur-1684]
	at net.minecraft.world.level.chunk.ChunkStatus.lambda$static$2(ChunkStatus.java:51) ~[purpur-1.19.jar:git-Purpur-1684]
	at net.minecraft.world.level.chunk.ChunkStatus.generate(ChunkStatus.java:275) ~[purpur-1.19.jar:git-Purpur-1684]
	at net.minecraft.server.level.ChunkTracker.lambda$scheduleChunkGeneration$37(ChunkTracker.java:1288) ~[?:?]
	at com.mojang.datafixers.util.Either$Left.map(Either.java:38) ~[purpur-1.19.jar:?]
	at net.minecraft.server.level.ChunkTracker.lambda$scheduleChunkGeneration$39(ChunkTracker.java:1286) ~[?:?]
	at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1150) ~[?:?]
	... 8 more

Additional details

Akiranya avatar Jun 29 '22 14:06 Akiranya

More information: the config of Terra is all default.

Akiranya avatar Jul 08 '22 13:07 Akiranya

Recent support threads with the same issue: https://discord.com/channels/715448651786485780/1018349066696007730 https://discord.com/channels/715448651786485780/1019021638546771978 https://discord.com/channels/715448651786485780/1017291363093581824

astrsh avatar Sep 12 '22 23:09 astrsh

latest.log Same issue, here's my log.

TheGam1ngWizard avatar Sep 13 '22 00:09 TheGam1ngWizard

Slightly troubleshooted to determine what the issue was: Was able to determine that issue is not replicatable on the v6.1.2 branch/release.

TheGam1ngWizard avatar Sep 13 '22 01:09 TheGam1ngWizard

Troubleshooted further (really just 'disabled half' testing on plugin similarities between affected users). Issue 100% replicatable when both Terra 6.2.0 and CommandAPI (https://www.spigotmc.org/resources/api-commandapi-1-13-1-19-2.62353/) are installed at the same time (no other plugins in combination required.)

TheGam1ngWizard avatar Sep 13 '22 01:09 TheGam1ngWizard

@Akiranya Temporary fix is disable CommandAPI.

TheGam1ngWizard avatar Sep 13 '22 01:09 TheGam1ngWizard

Thanks for all the investigations! Glad to hear the cause of problem was found. It was really helpful and I appreciated the help

Akiranya avatar Sep 13 '22 09:09 Akiranya

Not everyone reporting this issue have commandapi installed, fairly sure me and @Akiranya had it due to CommandAPI, but on the discord:

'Barni#6991' reports it with these plugins (AngelChest, AntiCombatLog, AntiNetherRoof*, AugmentedHardcore, BanItem, Breaker, Chunky, ChunkyBorder, Citizens, DiscordSRV, Essentials, EssentialsChat, EssentialsSpawn, LevelledMobs, LuckPerms, MythicMobs, Oraxen, PlaceholderAPI, ProtocolLib, Sentinel, ThirstPlugin, Tweakin, UltimateAutoRestart, WorldEdit, WorldGuard)

'Shiuki#7238' reports it with these plugins (Plugins: { ForcePack v1.2.1 com.convallyria.forcepack.spigot.ForcePackSpigot [SamB440], Skript v2.6.3 ch.njol.skript.Skript [Njol, Mirreski, SkriptLang Team, Contributors], SkBee v2.3.0 com.shanebeestudios.skbee.SkBee [ShaneBee], PL-Hide v1.5.21 me.nononitas.plhide.PLHide [Nononitas], Tether v2.4.1 me.naspo.tether.core.Tether [Naspo], Ships v6.0.0 org.core.implementation.bukkit.platform.plugin.boot.TranslateCoreBoot [], SkQuery v4.1.7 com.w00tmast3r.skquery.SkQuery [LimeGlass, w00tmast3r], VampireRevamp v1.0.BETA-17 com.clanjhoo.vampire.VampireRevamp [Cayorion, Mowstyl], OfflinePlayers v1.0 de.snap20lp.offlineplayers.OfflinePlayers [snap20lp], ProtocolSupport v1.18.2-1-dev protocolsupport.ProtocolSupport [Shevchik, 7kasper, MrPowerGamerBR, gdude2002], ProtocolLib v5.0.0-SNAPSHOT-b600 com.comphenix.protocol.ProtocolLib [dmulloy2, comphenix], Terra v6.2.0-BETA+7d056bd88 com.dfsek.terra.bukkit.TerraBukkitPlugin [dfsek], skRayFall v1.9.28 net.rayfall.eyesniper2.skrayfall.Core [eyesniper2], Sshac v6.19 shiuki.Sshac.Sshac [sh],})

TheGam1ngWizard avatar Sep 13 '22 12:09 TheGam1ngWizard

Hi, I saw this issue via CommandAPI's GitHub and thought I'd check it out. I was surprised that the CommandAPI, which focuses on the command system, could have done anything to disrupt chunk generation like this.

Looking into Terra's code by following this error message:

Caused by: java.lang.NullPointerException: Cannot invoke "com.dfsek.terra.api.util.generic.Lazy.value()" because the return value of "java.util.Map.get(Object)" is null
	at com.dfsek.terra.bukkit.nms.v1_19_R1.NMSChunkGeneratorDelegate.a(NMSChunkGeneratorDelegate.java:166) ~[Terra-bukkit-6.2.0-BETA+7d056bd88-shaded.jar:?]
...

it looks like these methods are causing the problem:

package com.dfsek.terra.bukkit.nms.v1_19_R1;

public class NMSChunkGeneratorDelegate extends ChunkGenerator {
    @Override
    public List<ChunkPos> getRingPositionsFor(@NotNull ConcentricRingsStructurePlacement structurePlacement,
                                              @NotNull RandomState noiseConfig) {
        ensureStructuresGenerated(noiseConfig);

        // error thrown by this line
        return ringPositions.get(structurePlacement).value();
    }

    @Override
    public void ensureStructuresGenerated(@NotNull RandomState noiseConfig) {
        if(!this.rings) {
            super.ensureStructuresGenerated(noiseConfig);
            this.populateStrongholdData(noiseConfig);
            this.rings = true;
        }
        
    }
    
    private void populateStrongholdData(RandomState noiseConfig) {
        LOGGER.info("Generating safe stronghold data. This may take up to a minute.");
        Set<Holder<Biome>> set = this.biomeSource.possibleBiomes();
        possibleStructureSets().map(Holder::value).forEach((holder) -> {
            boolean match = false;
            for(StructureSelectionEntry structureset_a : holder.structures()) {
                Structure structure = structureset_a.structure().value();
                Stream<Holder<Biome>> stream = structure.biomes().stream();
                if(stream.anyMatch(set::contains)) {
                    match = true;
                }
            }
            
            if(match) {
                if(holder.placement() instanceof ConcentricRingsStructurePlacement concentricringsstructureplacement) {
                    this.ringPositions.put(concentricringsstructureplacement, Lazy.lazy(
                            () -> this.generateRingPositions(holder, noiseConfig, concentricringsstructureplacement)));
                }
            }
        });
    }
}

Specifically, the error is thrown when ringPositions.get(structurePlacement) in getRingPositionsFor returns null when it isn't supposed to. This code looks like it handles stronghold generation, so my guess is that the error happens only when a chunk containing a stronghold is generated. This would be rare if you didn't know what to try and maybe the rarity of the issue prevented it from being replicated on the v6.1.2 branch/release or with plugins other than the CommandAPI.

I propose that the CommandAPI/other plugins are not causing this issue and it should be replicable with just Terra. I can't test this myself right now, but I plan to try as soon as I can.

willkroboth avatar Sep 13 '22 16:09 willkroboth

I tried replicating this bug but it never crashed for me... I tried on Paper (build 141) and Purpur (build 1777), with and without CommandAPI, teleporting to strongholds and just moving around, but nothing made it crash.

I'm using Terra 6.2.0-BETA, CommandAPI 8.5.1, and Minecraft 1.19.2, and I haven't done anything to the Terra config files. Has anyone else been able to trigger the crash with these latest versions? If not I would conclude that this bug was somehow fixed in the latest versions.

Any ideas on how to reproduce this for myself?

willkroboth avatar Sep 13 '22 21:09 willkroboth

????? What is going on then, I can 100% triggur this crash when utilzing just Paper build 141/142, with command API 8.5.1.

TheGam1ngWizard avatar Sep 13 '22 22:09 TheGam1ngWizard

Huh, maybe you could upload your server directory (or at least a minimal setup) and I could download and run it on my computer exactly as you have it? It'd be incredibly weird if this was OS related, but for the record I'm running Ubuntu Linux.

Additionally I don't think there is a minimum-plugin log file posted here yet so that might be helpful.

willkroboth avatar Sep 14 '22 01:09 willkroboth

Replicatable steps as follows:

Fresh install - only Terra active, generate world. Once world generates/player joins. - Shutdown server. Activate CommandAPI. Restart Server & join. Generate new chunks.

TheGam1ngWizard avatar Sep 14 '22 03:09 TheGam1ngWizard

Was able to reproduce by following these steps

Log for initial world creation https://mclo.gs/ySYR2Zt Log after CommandAPI was added https://mclo.gs/Q3fTRUx

astrsh avatar Sep 14 '22 03:09 astrsh

Based on this it seems like the NPE is thrown during chunk gen on an existing world after certain plugins have been added

astrsh avatar Sep 14 '22 03:09 astrsh

Hmm... following those steps I still can't get the server to crash. Here's my logs for comparison: CommandAPI test. I noticed that Astrashh had Chunky as well in their logs, so I tried that too, but still no crash: Chunky test.

One thing I noticed in both Astrashh's logs that I didn't have was these lines:

[Server thread/INFO]: [com.dfsek.terra.bukkit.nms.v1_19_R1.NMSInjectListener] Preparing to take over the world: world
[Server thread/INFO]: [com.dfsek.terra.bukkit.nms.v1_19_R1.NMSInjectListener] Successfully injected into world.

It seems that I'm missing the step where Terra takes over the overworld generation. If Terra's code isn't taking over for me, it would make sense that nothing special would be happening for me. I was starting from a completely fresh server, with everything from the previous tests deleted, so maybe you all have some leftover data that's affecting it?

willkroboth avatar Sep 14 '22 11:09 willkroboth

@willkroboth have you told Terra/Bukkit to override the regular worldgen in the 'Bukkit.yml' file?

You need to add

worlds:
  world:
    generator: Terra:OVERWORLD

for it to work as the generator.

TheGam1ngWizard avatar Sep 14 '22 12:09 TheGam1ngWizard

This may be completely irrelevant, but I thought I'd mention it anyway: the CommandAPI performs a post-server load resources reload. That is, after the server has finished loading, the CommandAPI triggers a modified internal /minecraft:reload, which will reload all resources. I'm not sure if this also reloads world generators, but that's a possibility.

More info can be found here: https://github.com/JorelAli/CommandAPI/blob/master/commandapi-nms/commandapi-1.19-common/src/main/java/dev/jorel/commandapi/nms/NMS_1_19_Common.java#L634

This doesn't explain the cases where this issue can arise without the CommandAPI, but it might help point things in the right direction?

(I'm currently on holiday, so I haven't investigated this issue personally, but this may help!)

JorelAli avatar Sep 14 '22 14:09 JorelAli

Oh, I think that may be the culprit

duplexsystem avatar Sep 14 '22 14:09 duplexsystem

Oh, I think that may be the culprit

Of course, as mentioned above, this doesn't explain other plugins (might be worth looking into ProtocolLib? Both logs above that didn't have the CommandAPI did have ProtocolLib). This also leads to whether Terra naturally supports regular /minecraft:reload or not - might be worth trying without the CommandAPI and using /minecraft:reload.

JorelAli avatar Sep 14 '22 19:09 JorelAli

Upon further testing:

Initial Setup Fresh Paper 1.19.2 # 141 server, with just Terra 6.2.0 and Chunky installed

  1. Start server with no world
    • New world initialized (configured as Terra world in bukkit.yml)
    • Initial chunks generate
    • Stronghold data gen gets triggered from this

Test A

  1. Run minecraft:reload
  2. Generate new chunks (via chunky or player join)
    • No NPEs ✅

Test B

  1. Stop server
  2. Start server
    • World that was created on previous startup loads
    • No new chunks generated
  3. Wait ~20 seconds
    • Stronghold data gen gets triggered after some time
  4. Run minecraft:reload
  5. Generate new chunks (via chunky or player join)
    • no NPEs ✅

Test C

  1. Stop server
  2. Start server
    • World that was created on previous startup loads
    • No new chunks generated
  3. Immediately run minecraft:reload
    • No stronghold data gen triggered
  4. Generate new chunks (via chunky or player join)
    • NPEs are thrown 🚫

Conclusion

If a datapack(?) reload occurs before stronghold data is created, chunk generation will throw NPEs (for Terra worlds)

CommandAPI performs a post-server load resources reload. That is, after the server has finished loading, the CommandAPI triggers a modified internal /minecraft:reload, which will reload all resources.

If my conclusion is correct, then this issue will occur with plugins that trigger resources to be reloaded before Terra is able to generate safe stronghold data. This doesn't happen for initial world creation because that seems to trigger the data gen before said plugins reload resources, hence why it only occurs with existing Terra worlds after server start.

astrsh avatar Sep 15 '22 02:09 astrsh

I'm not sure of the possible repercussions of this, but perhaps we could just return Collections.emptyList() whenever the ringPositions does not contain the requested ConcentricRingsStructurePlacement?.

Also, I believe what is possibly happening (just from intuition; I haven't looked at it in a debugger), is that for some reason the reloading is constructing new instances of ConcentricRingsStructurePlacement, which have not been populated into the map. I'd need to look at the source in a dev env to identify why it's not populating it right away, but I believe (?) it may have something to do with the rings variable not being reset when a reload is triggered?

This may also be a race condition that is, for some reason, causing possibleStructureSets() to return an empty list, because the reload has yet to populate it?

solonovamax avatar Sep 15 '22 21:09 solonovamax

Yeah, it might be a race condition that's happening because the pack reload has been triggered, but it hasn't finished so the structures aren't populated properly (?), causing possibleStructureSets() to return an empty list?? I could be very wrong, though.

solonovamax avatar Sep 15 '22 21:09 solonovamax

Actually, it could be these lines which is causing changes to the structure manager.

solonovamax avatar Sep 15 '22 21:09 solonovamax

I tried to solve this issue by returning null when the lazy is null, like this:

@Override
public List<ChunkPos> getRingPositionsFor(@NotNull ConcentricRingsStructurePlacement structurePlacement,
                                          @NotNull RandomState noiseConfig) {
    ensureStructuresGenerated(noiseConfig);
    Lazy<List<ChunkPos>> lazy = ringPositions.get(structurePlacement);
    return lazy == null ? null : lazy.value();
}

Looking at the method this overrides, I figured this would probably be fine:

@Nullable
public List<ChunkPos> getRingPositionsFor(ConcentricRingsStructurePlacement structurePlacement, RandomState noiseConfig) {
    this.ensureStructuresGenerated(noiseConfig);
    CompletableFuture<List<ChunkPos>> completablefuture = (CompletableFuture) this.ringPositions.get(structurePlacement);
    
    return completablefuture != null ? (List) completablefuture.join() : null;
}

While this stops the NPE from occurring, the game instead can't figure out where strongholds are supposed to be when CommandAPI is on the server. Even with this fix, there still seems to be an underlying problem where the ConcentricRingsStructurePlacement objects aren't being setup as is expected.

willkroboth avatar Sep 18 '22 21:09 willkroboth

One thing I noticed in my testing is if ring structure generation works correctly (case when CommandAPI isn't on the server), with the exception of the first time the server generates the world, the safe stronghold data generation always happens when the server is ticking and serving players. This causes a large lag spike, potentially timing out players. If this issue ends up changing the stronghold data generation process, it might be good to always generate the data while the server is starting up to avoid this lag spike.

Additionally, I'm having some weird exceptions when adding CommandAPI, attempting to generate new chunks, stopping the server, removing CommandAPI, then joining the server again when using my lazy-null-null patch from my previous comment. I get this sometimes when trying to throw an eye of ender, which kicks the player:

[07:10:49 ERROR]: Error whilst processing packet net.minecraft.network.protocol.game.PacketPlayInBlockPlace@50d9a14d for willkroboth[/127.0.0.1:58238]
java.lang.IllegalStateException: Somehow tried to find structures for a placement that doesn't exist
	at net.minecraft.world.level.chunk.ChunkGenerator.getNearestGeneratedStructure(ChunkGenerator.java:410) ~[paper-1.19.2.jar:git-Paper-141]
	at net.minecraft.world.level.chunk.ChunkGenerator.findNearestMapStructure(ChunkGenerator.java:355) ~[paper-1.19.2.jar:git-Paper-141]
	at net.minecraft.server.level.ServerLevel.findNearestMapStructure(ServerLevel.java:1904) ~[?:?]
	at net.minecraft.world.item.EnderEyeItem.use(EnderEyeItem.java:103) ~[?:?]
	at net.minecraft.world.item.ItemStack.use(ItemStack.java:497) ~[paper-1.19.2.jar:git-Paper-141]
	at net.minecraft.server.level.ServerPlayerGameMode.useItem(ServerPlayerGameMode.java:472) ~[?:?]
	at net.minecraft.server.network.ServerGamePacketListenerImpl.handleUseItem(ServerGamePacketListenerImpl.java:2046) ~[?:?]
	at net.minecraft.network.protocol.game.ServerboundUseItemPacket.handle(ServerboundUseItemPacket.java:32) ~[?:?]
	at net.minecraft.network.protocol.game.ServerboundUseItemPacket.a(ServerboundUseItemPacket.java:8) ~[?:?]
	at net.minecraft.network.protocol.PacketUtils.lambda$ensureRunningOnSameThread$1(PacketUtils.java:51) ~[?:?]
	at net.minecraft.server.TickTask.run(TickTask.java:18) ~[paper-1.19.2.jar:git-Paper-141]
	at net.minecraft.util.thread.BlockableEventLoop.doRunTask(BlockableEventLoop.java:153) ~[?:?]
	at net.minecraft.util.thread.ReentrantBlockableEventLoop.doRunTask(ReentrantBlockableEventLoop.java:24) ~[?:?]
	at net.minecraft.server.MinecraftServer.doRunTask(MinecraftServer.java:1361) ~[paper-1.19.2.jar:git-Paper-141]
	at net.minecraft.server.MinecraftServer.d(MinecraftServer.java:185) ~[paper-1.19.2.jar:git-Paper-141]
	at net.minecraft.util.thread.BlockableEventLoop.pollTask(BlockableEventLoop.java:126) ~[?:?]
	at net.minecraft.server.MinecraftServer.pollTaskInternal(MinecraftServer.java:1338) ~[paper-1.19.2.jar:git-Paper-141]
	at net.minecraft.server.MinecraftServer.pollTask(MinecraftServer.java:1331) ~[paper-1.19.2.jar:git-Paper-141]
	at net.minecraft.util.thread.BlockableEventLoop.runAllTasks(BlockableEventLoop.java:114) ~[?:?]
	at net.minecraft.server.MinecraftServer.tickServer(MinecraftServer.java:1465) ~[paper-1.19.2.jar:git-Paper-141]
	at net.minecraft.server.MinecraftServer.runServer(MinecraftServer.java:1193) ~[paper-1.19.2.jar:git-Paper-141]
	at net.minecraft.server.MinecraftServer.lambda$spin$0(MinecraftServer.java:305) ~[paper-1.19.2.jar:git-Paper-141]
	at java.lang.Thread.run(Thread.java:833) ~[?:?]
[07:10:49 INFO]: willkroboth lost connection: Packet processing error

I get a bunch of these when stopping the server, which seems to prevent the server process from finishing properly:

[07:11:46 ERROR]: Failed to schedule load callback for chunk [3, -18]
java.util.concurrent.CompletionException: java.lang.IllegalStateException: zip file closed
	at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:315) ~[?:?]
	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:320) ~[?:?]
	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1770) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
	at java.lang.Thread.run(Thread.java:833) ~[?:?]
Caused by: java.lang.IllegalStateException: zip file closed
	at java.util.zip.ZipFile.ensureOpen(ZipFile.java:831) ~[?:?]
	at java.util.zip.ZipFile.getEntry(ZipFile.java:330) ~[?:?]
	at java.util.jar.JarFile.getEntry(JarFile.java:518) ~[?:?]
	at java.util.jar.JarFile.getJarEntry(JarFile.java:473) ~[?:?]
	at org.bukkit.plugin.java.PluginClassLoader.findClass(PluginClassLoader.java:163) ~[paper-api-1.19.2-R0.1-SNAPSHOT.jar:?]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:587) ~[?:?]
	at org.bukkit.plugin.java.PluginClassLoader.loadClass0(PluginClassLoader.java:108) ~[paper-api-1.19.2-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.plugin.java.PluginClassLoader.loadClass(PluginClassLoader.java:103) ~[paper-api-1.19.2-R0.1-SNAPSHOT.jar:?]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:520) ~[?:?]
	at com.dfsek.terra.bukkit.generator.BukkitChunkGeneratorWrapper.generateNoise(BukkitChunkGeneratorWrapper.java:67) ~[Terra-bukkit-6.2.0-BETA+e8fa5514c-shaded.jar:?]
	at org.bukkit.craftbukkit.v1_19_R1.generator.CustomChunkGenerator.lambda$fillFromNoise$0(CustomChunkGenerator.java:254) ~[paper-1.19.2.jar:git-Paper-141]
	at org.bukkit.craftbukkit.v1_19_R1.generator.CustomChunkGenerator.lambda$fillFromNoise$1(CustomChunkGenerator.java:259) ~[paper-1.19.2.jar:git-Paper-141]
	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1768) ~[?:?]
	... 3 more

Here's my logs for this: https://paste.gg/p/anonymous/5db87fd36cc64c5cb2cea644dd1013f8 These issues will probably be resolved along with the main NPE, but it seems to show that there are persistent issues after generating new chucks with the CommandAPI active.

willkroboth avatar Sep 19 '22 11:09 willkroboth

Huh, I actually got those two errors to happen with an unmodified version of Terra as the only plugin. Here's the log: https://paste.gg/p/anonymous/b088f9627abd427b9719a45d6d995135. It seems the pack processing kick happens when an eye of ender is thrown before the safe stronghold generation is complete. The chunk load callback error seems to happen when the server is stopped while chunks are being generated. I seem to have found two new bugs, but it'd be good if someone could replicate this separately.

willkroboth avatar Sep 24 '22 21:09 willkroboth

Paper has recently rewritten it's chuck generation system. As far as I can tell, everything is working the same (same bugs), but noticeably faster.

willkroboth avatar Sep 26 '22 12:09 willkroboth

For now, let's focus on fixing the issue on the old chunk gen system, before looking at the new one, as hopefully a fix for the old one should fix the new one as well.

solonovamax avatar Sep 26 '22 18:09 solonovamax

I'm gonna try and look at the mc sources later to see exactly how mc handles ensureStructuresGenerated, as I really believe it's that guy causing issues. (Because the ring positions have been generated once before the reload, so after reload, the map no longer contains correct data and it's not generated again)

solonovamax avatar Sep 26 '22 18:09 solonovamax