Huge resource usage over time, eventually crashes the server (1.13.2)

Discussion in 'Spigot Help' started by Tufan, Jul 10, 2019 at 2:42 PM.

  1. There is a huge increase in resource usage over time using the latest PaperSpigot 1.13.2 build (also happens with spigot, was hoping for it to be gone when switching to paper but nah) and I ran out of ideas how to fix it.

    1 Players, whitelisted server, over 3gb memory usage and 100% CPU usage in 30 minutes, keeps increasing until it crashes.

    Here's a list of plugins I have:
    BungeeTabListPlus, ChatControl, ClearLag, CorgiPrison (Custom), DiscordSRV, EssentialCommands(Custom), Essentials, EssentialsSpawn, FastAsyncWorldEdit, FeatherBoard, HolographicDisplays, InsaneShops, LagAssist, mcMMO, Multiverse-Core, MVdWPlaceholderAPI, PlaceholderAPI, PlotSquared, ProtocolLib, Spartan, SpigotVoteRewards (Custom), UltraPermissions, Vault, ViaVersion, VoidGenerator, Votifier, WorldEdit, WorldGuard, WorldGuardExtraFlags

    I tried removing every single plugin except Multiverse-Core (4.0.0), unfortunately, even if it is the problem I couldn't find a replacement for it.

    I highly suspect this is related to spigot, I googled the issue and found lots of other people having the exact same problem with different plugins.

    Reloading featherboard or using ClearLag:lagg gc resets the memory usage, it is what keeps my server alive right now.

    Start script:
    java -d64 -Xmx1536M -Xms1536M -XX:parallelGCThreads=8 -XX:+AggressiveOpts -XX:+UseFastAccessorMethods -XX:+UseParallelGC -jar paper.jar

    Errors when resource usage crashes the server:
    [Wed, 10. Jul 2019 13:17:05 UTC ERROR] --- DO NOT REPORT THIS TO PAPER - THIS IS NOT A BUG OR A CRASH - git-Paper-636 (MC: 1.13.2) --- [Wed, 10. Jul 2019 13:17:05 UTC ERROR] The server has not responded for 10 seconds! Creating thread dump



    [Wed, 10. Jul 2019 13:17:06 UTC ERROR] ------------------------------ [Wed, 10. Jul 2019 13:17:08 UTC ERROR] Server thread dump (Look for plugins here before reporting to Paper!): [Wed, 10. Jul 2019 13:17:12 UTC INFO] [WorldGuard] Region data changes made in 'void' have been background saved



    [Wed, 10. Jul 2019 13:17:18 UTC ERROR] ------------------------------ [Wed, 10. Jul 2019 13:17:18 UTC INFO] [ChatControl 8.2.10] loading component part [Chat.First_Part] took 5341.56 ms



    [Wed, 10. Jul 2019 13:17:19 UTC INFO] [ChatControl 8.2.10] creating component [Chat] took 5801.04 ms [Wed, 10. Jul 2019 13:17:19 UTC ERROR] Current Thread: Server thread [Wed, 10. Jul 2019 13:17:20 UTC ERROR] PID: 18 | Suspended: false | Native: false | State: RUNNABLE [Wed, 10. Jul 2019 13:17:20 UTC ERROR] Stack:



    [Wed, 10. Jul 2019 13:17:26 UTC ERROR] java.lang.Class.forName0(Native Method) [Wed, 10. Jul 2019 13:17:27 UTC ERROR] java.lang.Class.forName(Class.java:264) [Wed, 10. Jul 2019 13:17:27 UTC ERROR] com.esotericsoftware.yamlbeans.Beans.getDeferredConstruction(Beans.java:53) [Wed, 10. Jul 2019 13:17:30 UTC ERROR] com.esotericsoftware.yamlbeans.YamlReader.createObject(YamlReader.java:361) [Wed, 10. Jul 2019 13:17:31 UTC ERROR] com.esotericsoftware.yamlbeans.YamlReader.readValueInternal(YamlReader.java:264)



    [Wed, 10. Jul 2019 13:17:36 UTC ERROR] com.esotericsoftware.yamlbeans.YamlReader.readValue(YamlReader.java:152) [Wed, 10. Jul 2019 13:17:36 UTC ERROR] com.esotericsoftware.yamlbeans.YamlReader.readValueInternal(YamlReader.java:285)



    [Wed, 10. Jul 2019 13:17:41 UTC ERROR] com.esotericsoftware.yamlbeans.YamlReader.readValue(YamlReader.java:152) [Wed, 10. Jul 2019 13:17:41 UTC ERROR] com.esotericsoftware.yamlbeans.YamlReader.read(YamlReader.java:103) [Wed, 10. Jul 2019 13:17:42 UTC ERROR] com.esotericsoftware.yamlbeans.YamlReader.read(YamlReader.java:90) [Wed, 10. Jul 2019 13:17:42 UTC ERROR] com.esotericsoftware.yamlbeans.YamlReader.read(YamlReader.java:84) [Wed, 10. Jul 2019 13:17:42 UTC ERROR] de.leonhard.storage.Yaml.update(Yaml.java:401) [Wed, 10. Jul 2019 13:17:43 UTC ERROR] de.leonhard.storage.Yaml.reload(Yaml.java:393) [Wed, 10. Jul 2019 13:17:43 UTC ERROR] de.leonhard.storage.Yaml.has(Yaml.java:292)



    [Wed, 10. Jul 2019 13:17:46 UTC ERROR] de.leonhard.storage.Yaml.contains(Yaml.java:288) [Wed, 10. Jul 2019 13:17:49 UTC ERROR] de.leonhard.storage.Yaml.getInt(Yaml.java:224) [Wed, 10. Jul 2019 13:17:50 UTC ERROR] com.tufapps.corgi.Prison.Tasks.MineResetTick.run(MineResetTick.java:15) [Wed, 10. Jul 2019 13:17:53 UTC ERROR] org.bukkit.craftbukkit.v1_13_R2.scheduler.CraftTask.run(CraftTask.java:84) [Wed, 10. Jul 2019 13:17:53 UTC ERROR] org.bukkit.craftbukkit.v1_13_R2.scheduler.CraftScheduler.mainThreadHeartbeat(CraftScheduler.java:449) [Wed, 10. Jul 2019 13:17:54 UTC ERROR] net.minecraft.server.v1_13_R2.MinecraftServer.b(MinecraftServer.java:1010)



    [Wed, 10. Jul 2019 13:17:54 UTC ERROR] net.minecraft.server.v1_13_R2.DedicatedServer.b(DedicatedServer.java:439) [Wed, 10. Jul 2019 13:17:55 UTC ERROR] net.minecraft.server.v1_13_R2.MinecraftServer.a(MinecraftServer.java:940) [Wed, 10. Jul 2019 13:17:57 UTC ERROR] net.minecraft.server.v1_13_R2.MinecraftServer.run(MinecraftServer.java:837) [Wed, 10. Jul 2019 13:17:57 UTC ERROR] java.lang.Thread.run(Thread.java:748)



    [Wed, 10. Jul 2019 13:18:00 UTC ERROR] ------------------------------ [Wed, 10. Jul 2019 13:18:00 UTC ERROR] --- DO NOT REPORT THIS TO PAPER - THIS IS NOT A BUG OR A CRASH --- [Wed, 10. Jul 2019 13:18:05 UTC ERROR] ------------------------------



    [Wed, 10. Jul 2019 13:18:16 UTC ERROR] --- DO NOT REPORT THIS TO PAPER - THIS IS NOT A BUG OR A CRASH - git-Paper-636 (MC: 1.13.2) --- [Wed, 10. Jul 2019 13:18:16 UTC ERROR] The server has not responded for 26 seconds! Creating thread dump [Wed, 10. Jul 2019 13:18:17 UTC ERROR] ------------------------------ [Wed, 10. Jul 2019 13:18:17 UTC ERROR] Server thread dump (Look for plugins here before reporting to Paper!): [Wed, 10. Jul 2019 13:18:18 UTC ERROR] ------------------------------ [Wed, 10. Jul 2019 13:18:18 UTC ERROR] Current Thread: Server thread [Wed, 10. Jul 2019 13:18:19 UTC ERROR] PID: 18 | Suspended: false | Native: false | State: RUNNABLE



    [Wed, 10. Jul 2019 13:18:22 UTC ERROR] Stack: [Wed, 10. Jul 2019 13:18:22 UTC ERROR] java.lang.Class.forName0(Native Method) [Wed, 10. Jul 2019 13:18:22 UTC ERROR] java.lang.Class.forName(Class.java:264) [Wed, 10. Jul 2019 13:18:23 UTC ERROR] com.esotericsoftware.yamlbeans.Beans.getDeferredConstruction(Beans.java:53)



    [Wed, 10. Jul 2019 13:18:32 UTC ERROR] com.esotericsoftware.yamlbeans.YamlReader.createObject(YamlReader.java:361) [Wed, 10. Jul 2019 13:18:33 UTC ERROR] com.esotericsoftware.yamlbeans.YamlReader.readValueInternal(YamlReader.java:264) [Wed, 10. Jul 2019 13:18:33 UTC ERROR] com.esotericsoftware.yamlbeans.YamlReader.readValue(YamlReader.java:152) [Wed, 10. Jul 2019 13:18:34 UTC ERROR] com.esotericsoftware.yamlbeans.YamlReader.read(YamlReader.java:103) [Wed, 10. Jul 2019 13:18:35 UTC ERROR] com.esotericsoftware.yamlbeans.YamlReader.read(YamlReader.java:90)



    [Wed, 10. Jul 2019 13:18:35 UTC ERROR] com.esotericsoftware.yamlbeans.YamlReader.read(YamlReader.java:84) [Wed, 10. Jul 2019 13:18:38 UTC ERROR] de.leonhard.storage.Yaml.update(Yaml.java:401) [Wed, 10. Jul 2019 13:18:39 UTC ERROR] de.leonhard.storage.Yaml.reload(Yaml.java:393) [Wed, 10. Jul 2019 13:18:39 UTC ERROR] de.leonhard.storage.Yaml.has(Yaml.java:292) [Wed, 10. Jul 2019 13:18:40 UTC ERROR] de.leonhard.storage.Yaml.contains(Yaml.java:288) [Wed, 10. Jul 2019 13:18:40 UTC ERROR] de.leonhard.storage.Yaml.getInt(Yaml.java:224)

    As I mentioned above, I tried without every single plugin except multiverse-core, which makes me think this is a spigot issue.
     
  2. This seems to be your server timing out, usually a memory or plugin issue. Try using /timings (a feature with paperspigot) and see what's using so much of your system.
     
  3. Try doing a heap dump and use some program to analize it
     
  4. As I said, use timings.
     
  5. Will try timings but I don't really have any TPS drops, just ram exceeding the maximum memory limit and server crashing.

    So I really don't know how to look at heap dumps, I'm probably not looking at the right thing right now but I suspect this is the leak.
    http://prntscr.com/od6xsg
    http://prntscr.com/od6wze
    http://prntscr.com/od6x5y
    http://prntscr.com/od6xaj

    I still don't know how they are related to a plugin, or how am I supposed to find that relation.
     
  6. Unfortunately I could not get timings of a crash, here's timings of 10 minutes of mining.
    https://timings.aikar.co/?id=4b06d96a7ebf4937ae1625fe6ba1d2f6
    I believe it has something to do with chunk loading/unloading. Tried removing almost all of the plugins.
     
  7. Okay so, the server just crashed in 20% memory usage, so the main issue is not memory leak here.
    It also happened on 1.12.2 so spigot isn't the one to blame either.

    [Wed, 10. Jul 2019 22:14:59 UTC ERROR] --- DO NOT REPORT THIS TO PAPER - THIS IS NOT A BUG OR A CRASH --- [Wed, 10. Jul 2019 22:14:59 UTC ERROR] The server has not responded for 14 seconds! Creating thread dump [Wed, 10. Jul 2019 22:15:00 UTC ERROR] ------------------------------ [Wed, 10. Jul 2019 22:15:00 UTC ERROR] Server thread dump (Look for plugins here before reporting to Paper!):



    [Wed, 10. Jul 2019 22:15:10 UTC ERROR] ------------------------------ [Wed, 10. Jul 2019 22:15:11 UTC ERROR] Current Thread: Server thread [Wed, 10. Jul 2019 22:15:11 UTC ERROR] PID: 17 | Suspended: false | Native: false | State: RUNNABLE [Wed, 10. Jul 2019 22:15:11 UTC ERROR] Stack: [Wed, 10. Jul 2019 22:15:11 UTC ERROR] java.lang.Throwable.getStackTraceElement(Native Method) [Wed, 10. Jul 2019 22:15:11 UTC ERROR] java.lang.System$2.getStackTraceElement(System.java:1261) [Wed, 10. Jul 2019 22:15:11 UTC ERROR] com.boydti.fawe.bukkit.v0.ChunkListener_8.getElement(ChunkListener_8.java:14) [Wed, 10. Jul 2019 22:15:11 UTC ERROR] com.boydti.fawe.bukkit.v0.ChunkListener.onChunkLoad(ChunkListener.java:331) [Wed, 10. Jul 2019 22:15:11 UTC ERROR] com.destroystokyo.paper.event.executor.asm.generated.GeneratedEventExecutor427.execute(Unknown Source) [Wed, 10. Jul 2019 22:15:11 UTC ERROR] org.bukkit.plugin.EventExecutor$2.execute(EventExecutor.java:70) [Wed, 10. Jul 2019 22:15:11 UTC ERROR] co.aikar.timings.TimedEventExecutor.execute(TimedEventExecutor.java:78) [Wed, 10. Jul 2019 22:15:11 UTC ERROR] org.bukkit.plugin.RegisteredListener.callEvent(RegisteredListener.java:62) [Wed, 10. Jul 2019 22:15:11 UTC ERROR] org.bukkit.plugin.SimplePluginManager.callEvent(SimplePluginManager.java:513) [Wed, 10. Jul 2019 22:15:11 UTC ERROR] net.minecraft.server.v1_12_R1.Chunk.loadNearby(Chunk.java:1103) [Wed, 10. Jul 2019 22:15:11 UTC ERROR] org.bukkit.craftbukkit.v1_12_R1.chunkio.ChunkIOProvider.callStage2(ChunkIOProvider.java:59) [Wed, 10. Jul 2019 22:15:12 UTC ERROR] org.bukkit.craftbukkit.v1_12_R1.chunkio.ChunkIOProvider.callStage2(ChunkIOProvider.java:16) [Wed, 10. Jul 2019 22:15:12 UTC ERROR] org.bukkit.craftbukkit.v1_12_R1.util.AsynchronousExecutor$Task.finish(AsynchronousExecutor.java:188) [Wed, 10. Jul 2019 22:15:12 UTC ERROR] org.bukkit.craftbukkit.v1_12_R1.util.AsynchronousExecutor.finishActive(AsynchronousExecutor.java:347)



    [Wed, 10. Jul 2019 22:15:12 UTC ERROR] org.bukkit.craftbukkit.v1_12_R1.chunkio.ChunkIOExecutor.tick(ChunkIOExecutor.java:36) [Wed, 10. Jul 2019 22:15:12 UTC ERROR] net.minecraft.server.v1_12_R1.MinecraftServer.D(MinecraftServer.java:866) [Wed, 10. Jul 2019 22:15:12 UTC ERROR] net.minecraft.server.v1_12_R1.DedicatedServer.D(DedicatedServer.java:423) [Wed, 10. Jul 2019 22:15:12 UTC ERROR] net.minecraft.server.v1_12_R1.MinecraftServer.C(MinecraftServer.java:774) [Wed, 10. Jul 2019 22:15:12 UTC ERROR] net.minecraft.server.v1_12_R1.MinecraftServer.run(MinecraftServer.java:666) [Wed, 10. Jul 2019 22:15:12 UTC ERROR] java.lang.Thread.run(Thread.java:748) [Wed, 10. Jul 2019 22:15:12 UTC ERROR] ------------------------------ [Wed, 10. Jul 2019 22:15:12 UTC ERROR] --- DO NOT REPORT THIS TO PAPER - THIS IS NOT A BUG OR A CRASH --- [Wed, 10. Jul 2019 22:15:12 UTC ERROR] ------------------------------ [Wed, 10. Jul 2019 22:15:12 UTC ERROR] --- DO NOT REPORT THIS TO PAPER - THIS IS NOT A BUG OR A CRASH --- [Wed, 10. Jul 2019 22:15:12 UTC ERROR] The server has not responded for 28 seconds! Creating thread dump [Wed, 10. Jul 2019 22:15:12 UTC ERROR] ------------------------------ [Wed, 10. Jul 2019 22:15:12 UTC ERROR] Server thread dump (Look for plugins here before reporting to Paper!): [Wed, 10. Jul 2019 22:15:12 UTC ERROR] ------------------------------ [Wed, 10. Jul 2019 22:15:12 UTC ERROR] Current Thread: Server thread [Wed, 10. Jul 2019 22:15:12 UTC ERROR] PID: 17 | Suspended: false | Native: false | State: RUNNABLE [Wed, 10. Jul 2019 22:15:12 UTC ERROR] Stack: [Wed, 10. Jul 2019 22:15:12 UTC ERROR] net.minecraft.server.v1_12_R1.WorldGenCanyon.a(SourceFile:119) [Wed, 10. Jul 2019 22:15:12 UTC ERROR] net.minecraft.server.v1_12_R1.WorldGenCanyon.a(SourceFile:190) [Wed, 10. Jul 2019 22:15:13 UTC ERROR] net.minecraft.server.v1_12_R1.WorldGenBase.a(SourceFile:34)



    [Wed, 10. Jul 2019 22:15:13 UTC ERROR] net.minecraft.server.v1_12_R1.ChunkProviderGenerate.getOrCreateChunk(ChunkProviderGenerate.java:168) [Wed, 10. Jul 2019 22:15:13 UTC ERROR] org.bukkit.craftbukkit.v1_12_R1.generator.NormalChunkGenerator.getOrCreateChunk(NormalChunkGenerator.java:36) [Wed, 10. Jul 2019 22:15:13 UTC ERROR] co.aikar.timings.TimedChunkGenerator.getOrCreateChunk(TimedChunkGenerator.java:93) [Wed, 10. Jul 2019 22:15:13 UTC ERROR] net.minecraft.server.v1_12_R1.ChunkProviderServer.originalGetChunkAt(ChunkProviderServer.java:200) [Wed, 10. Jul 2019 22:15:13 UTC ERROR] net.minecraft.server.v1_12_R1.ChunkProviderServer.getChunkAt(ChunkProviderServer.java:180) [Wed, 10. Jul 2019 22:15:13 UTC ERROR] net.minecraft.server.v1_12_R1.PlayerChunk.a(PlayerChunk.java:123) [Wed, 10. Jul 2019 22:15:13 UTC ERROR] net.minecraft.server.v1_12_R1.PlayerChunkMap.flush(PlayerChunkMap.java:185) [Wed, 10. Jul 2019 22:15:13 UTC ERROR] net.minecraft.server.v1_12_R1.WorldServer.doTick(WorldServer.java:332) [Wed, 10. Jul 2019 22:15:13 UTC ERROR] net.minecraft.server.v1_12_R1.MinecraftServer.D(MinecraftServer.java:905) [Wed, 10. Jul 2019 22:15:13 UTC ERROR] net.minecraft.server.v1_12_R1.DedicatedServer.D(DedicatedServer.java:423) [Wed, 10. Jul 2019 22:15:13 UTC ERROR] net.minecraft.server.v1_12_R1.MinecraftServer.C(MinecraftServer.java:774) [Wed, 10. Jul 2019 22:15:13 UTC ERROR] net.minecraft.server.v1_12_R1.MinecraftServer.run(MinecraftServer.java:666) [Wed, 10. Jul 2019 22:15:13 UTC ERROR] java.lang.Thread.run(Thread.java:748) [Wed, 10. Jul 2019 22:15:13 UTC ERROR] ------------------------------ [Wed, 10. Jul 2019 22:15:13 UTC ERROR] --- DO NOT REPORT THIS TO PAPER - THIS IS NOT A BUG OR A CRASH --- [Wed, 10. Jul 2019 22:15:13 UTC ERROR] ------------------------------

    Looking at the errors, I can probably say that the issue is directly related to chunk loading/unloading. As far as I know the only plugins that does anything with chunks is MV-Core and FAWE, I'll try removing them one by one and post updates here.
     
  8. This is a chunk loading crash. It means your chunks are corrupt, I recommend you delete/reset that world. Looking at your timings, I recommend you looking at these plugins
    [​IMG].
    Also, you can't really run a server well with 2G of RAM.
    Judging from your RAM, your server probably crashed whilst loading a chunk with large amounts of data or many chunks at once which corrupted one of them and is now crashing your server.
     
  9. There's 2 worlds, both are recently created. One is a flatworld with no structures, other is a void world with absolutely nothing in it.
    CorgiPrison is the heart of the server, almost all commands and features depends on it. The main reason it uses a lot of ticking is because bukkit doesn't allow async block replacement, therefore this method is called every 90 seconds with thousands of blocks, it does not casuse noticeable in-game lag, this plugin is not installed on my survival server, which also has the same problem. I also tried removing FeatherBoard and it didn't change anything.

    Unless Multiverse-Core's FLAT generator is generating corrupted chunks, I don't think it is possible that chunks are corrupted. I tried everything, at this point I blame Vultr as it also crashes if I save 2 files at the same time, will move my servers to a OVH dedicated instance soon, if that doesn't fix the problem I don't know what will.
    The only plugin that all my servers has in common that interacts with world is Multiverse-Core, which is also the only plugin I didn't try removing.
     
  10. Moved to OVH's GAME-32 instance, the server has been running with 8GB for hours at 20TPS without a crash, guess that was about lack of resources or some of vultr's limitations that I don't know.

    UPDATE: It happened again after 4 hours :(
     
    #10 Tufan, Jul 12, 2019 at 11:40 AM
    Last edited: Jul 12, 2019 at 1:13 PM