LunaPixelStudios / Medieval-MC

https://lunapixel.studio/discord
https://lunapixel.studio/discord
15 stars 9 forks source link

Server randomly freezes for 2 minutes before crashing #484

Closed glentakahashi closed 1 year ago

glentakahashi commented 1 year ago

Describe the Bug

Randomly, although I seem to notice it more often when doing chunk generation (either via cli or just exploring in game), the server will seemingly just freeze on a tick for 120 seconds until the server crashes and restarts. The server logs don't have anything useful prior to the crash, and i haven't found anything in the crash reports either.

As an example of logs before a crash I usually see this

[16:45:28] [Worker-Main-245/WARN]: Empty height range: biased[-10 absolute--15 absolute inner: 1]
[16:45:51] [Worker-Main-248/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:45:51] [Worker-Main-248/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:45:52] [Worker-Main-248/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:46:18] [Worker-Main-245/ERROR]: Hanging entity at invalid position: class_2338{x=-71, y=6, z=-215}
[16:46:19] [Worker-Main-248/ERROR]: Hanging entity at invalid position: class_2338{x=-71, y=7, z=-210}
[16:46:25] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:46:25] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:46:25] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:46:25] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:46:25] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:46:25] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:46:25] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:46:25] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:46:25] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:46:25] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:46:26] [Worker-Main-248/WARN]: Tried to access a block entity before it was created. class_2338{x=-3073, y=-28, z=1935}
[16:46:26] [Worker-Main-248/WARN]: Tried to access a block entity before it was created. class_2338{x=-3073, y=-28, z=1929}
[16:46:34] [Worker-Main-248/ERROR]: Hanging entity at invalid position: class_2338{x=-71, y=6, z=-215}
[16:46:34] [Worker-Main-248/ERROR]: Hanging entity at invalid position: class_2338{x=-71, y=7, z=-210}
[16:46:44] [Worker-Main-248/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:47:03] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:47:03] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:47:03] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:47:03] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:47:03] [Worker-Main-245/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[16:49:16] [Server Watchdog/ERROR]: A single server tick took 120.00 seconds (should be max 0.05)
[16:49:16] [Server Watchdog/ERROR]: Considering it to be crashed, server will forcibly shutdown.
[16:49:17] [Server Watchdog/ERROR]: This crash report has been saved to: /opt/minecraft/MMC/./crash-reports/crash-2022-12-22_16.49.17-server.txt
[11:20:17] [Worker-Main-757/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[11:20:17] [Worker-Main-757/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[11:20:17] [Worker-Main-755/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[11:20:18] [Worker-Main-740/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[11:20:18] [Worker-Main-740/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[11:21:25] [Worker-Main-846/WARN]: Ignoring unknown attribute 'forge:entity_gravity'
[11:21:26] [Worker-Main-842/ERROR]: Hanging entity at invalid position: class_2338{x=255, y=7, z=-24}
[11:21:26] [Worker-Main-842/ERROR]: Hanging entity at invalid position: class_2338{x=259, y=6, z=-25}
[11:21:30] [Worker-Main-752/ERROR]: Hanging entity at invalid position: class_2338{x=255, y=7, z=-24}
[11:21:30] [Worker-Main-752/ERROR]: Hanging entity at invalid position: class_2338{x=259, y=6, z=-25}
[11:21:33] [Worker-Main-762/ERROR]: Hanging entity at invalid position: class_2338{x=255, y=8, z=2}
[11:21:33] [Worker-Main-762/ERROR]: Hanging entity at invalid position: class_2338{x=255, y=7, z=0}
[11:21:33] [Worker-Main-762/ERROR]: Hanging entity at invalid position: class_2338{x=257, y=6, z=2}
[11:21:33] [Worker-Main-762/ERROR]: Hanging entity at invalid position: class_2338{x=256, y=6, z=0}
[11:21:35] [Worker-Main-840/ERROR]: Hanging entity at invalid position: class_2338{x=255, y=7, z=-24}
[11:21:35] [Worker-Main-840/ERROR]: Hanging entity at invalid position: class_2338{x=259, y=6, z=-25}
[11:21:36] [Worker-Main-754/ERROR]: Hanging entity at invalid position: class_2338{x=255, y=7, z=-24}
[11:21:36] [Worker-Main-754/ERROR]: Hanging entity at invalid position: class_2338{x=259, y=6, z=-25}
[11:21:38] [Worker-Main-740/ERROR]: Hanging entity at invalid position: class_2338{x=255, y=7, z=-24}
[11:21:38] [Worker-Main-740/ERROR]: Hanging entity at invalid position: class_2338{x=259, y=6, z=-25}
[11:21:38] [Worker-Main-844/ERROR]: Hanging entity at invalid position: class_2338{x=255, y=7, z=-24}
[11:21:38] [Worker-Main-844/ERROR]: Hanging entity at invalid position: class_2338{x=259, y=6, z=-25}
[11:21:44] [Worker-Main-740/ERROR]: Hanging entity at invalid position: class_2338{x=255, y=8, z=2}
[11:21:44] [Worker-Main-740/ERROR]: Hanging entity at invalid position: class_2338{x=255, y=7, z=0}
[11:21:44] [Worker-Main-740/ERROR]: Hanging entity at invalid position: class_2338{x=257, y=6, z=2}
[11:21:44] [Worker-Main-740/ERROR]: Hanging entity at invalid position: class_2338{x=256, y=6, z=0}
[11:21:44] [Worker-Main-846/ERROR]: Hanging entity at invalid position: class_2338{x=255, y=7, z=-24}
[11:21:44] [Worker-Main-846/ERROR]: Hanging entity at invalid position: class_2338{x=259, y=6, z=-25}
[11:21:44] [Worker-Main-740/ERROR]: Hanging entity at invalid position: class_2338{x=255, y=7, z=-24}
[11:21:44] [Worker-Main-740/ERROR]: Hanging entity at invalid position: class_2338{x=259, y=6, z=-25}
[11:23:59] [Server Watchdog/ERROR]: A single server tick took 120.00 seconds (should be max 0.05)
[11:23:59] [Server Watchdog/ERROR]: Considering it to be crashed, server will forcibly shutdown.
[11:24:00] [Server Watchdog/ERROR]: This crash report has been saved to: /opt/minecraft/MMC/./crash-reports/crash-2022-12-22_11.24.00-server.txt

Reproduction Steps

No response

Screenshots and Videos

No response

Crash Report or Log

https://gist.github.com/glentakahashi/63b4ed5c9827c4bd586e435eecaca1d2

Operating System

linux (amazon linux 2)

Minecraft Version

1.19

Modloader

Fabric

Modpack Version

mmc v14.5

Optifine

No

Other Mods

No response

chorbintime commented 1 year ago

Did you modify the modpack in any way?

Did you update any mods manually?

Follow this guide. https://github.com/etil2jz/etil-minecraft-flags If the lag persists set maxticktime in server.properties to -1 and then run the command /spark profiler --interval 100

glentakahashi commented 1 year ago

Aha, i think i figured out the cause. using Spark never helped because it froze the entire thread and never returned so i couldn't get a profile. However I was able to take stack traces using jstack and found that in the 3 times that the game froze it was stuck on com.telepathicgrunt.repurposedstructures.misc.maptrades.StructureSpecificMaps$TreasureMapForEmeralds.method_7246(StructureSpecificMaps.java:68)

I dug into that source code and found https://github.com/TelepathicGrunt/RepurposedStructures/blob/71839a80a79a34089ac89e47c6eb48d310447a78/src/main/java/com/telepathicgrunt/repurposedstructures/misc/maptrades/StructureSpecificMaps.java#L89

This led me to do some more searching and I found this bug https://bugs.mojang.com/browse/MC-249136 that seems related and the exact same behavior I noticed as well.

I /think/ i fixed it (edit: ran chunk gen for 6 hours without any crashes) by making a custom datapack which removes map trades from villagers for Repurposed Structures. Repurposed_Structures-NoMaps.zip I also added https://github.com/PaperMC/Paper/issues/2312#issuecomment-673210233 just in case, although I wasn't particularly seeing issues with that afaict.

TelepathicGrunt commented 1 year ago

@glentakahashi I’m the dev for Repurposed Structures. I had tested my structures before and they have been spawning so my first thing is this is something unique to your world or pack.

Go into your game and use /locate command on these structure tags/structures until you get a deadlock and tell me which one is causing the game to tp get stuck longer than 30 seconds. https://github.com/TelepathicGrunt/RepurposedStructures/blob/latest-released-Forge/src/main/resources/data/repurposed_structures/structure_map_trades/default_maps.json

the only way this can happen is if the biomes that the structure can spawn in is in the world’s biome source’s possible biomes field but the biome source is not actually spawning the biomes or conditions are never right for the structure.

For example, Jungle Fortress needs a decent area to be all jungle to fit the structure in. If you have something messing with biome size and making microbiomes, there won’t be a large enough jungle area for it so the game gets stuck searching forever.

So first, find exactly what structure tag is deadlocking your game and then I can explain the conditions those structures needs and then we can look closer at the world generation going on.

glentakahashi commented 1 year ago

Ah @TelepathicGrunt that might explain it then, searching for the collections/ ones happens instantly, but it doesn't work at all for the other tags. Maybe this modpack removed them or they're not available for some reason? I get the message There is no structure with type #repurposed_structures:fortress_jungle

@chorbintime does this modpack disable/remove some structures or am i doing something wrong in querying them

Edit: nevermind i was querying it wrong. I searched for all the structures and they worked relatively instantly. Should i be testing this from far away from spawn?

TelepathicGrunt commented 1 year ago

Then the structures are spawning, working, and locatable. This then points to something messing with the explorer maps/wandering trader themselves. (Unless the issue is happening in a specific world and not new worlds created. If it is world specific, can you share the world?)

If you spawn the wandering trader by spawn egg and open their trades until you get one with an explorer map, does it deadlock then?

glentakahashi commented 1 year ago

Hmm okay so i literally can't repro this any more which is super annoying, even though it used to happen constantly. I spun up new servers with the same seed, did the same pregenning, restored from a backup etc. and now it doesn't happen...

I also tried creating a ton of wandering traders and finding ones with maps, and I got some lag (like 1-2 seconds max) but nothing crazy like the 2 minutes i was seeing before.

I'm going to close out for now and will revisit in the future if i can get a repro, but i still have some leads to dig into