[MC-209819] Server crash when pathfinding to player that is teleporting away

I've had this crash dozens of times throughout 1.16.x (and possibly earlier) on my public vanilla server. It's not easy to reproduce as it does not happen frequently, but every time it does happen it's because a player has teleported away from an area while there were mobs aggroed by him, as far as I can tell always zombified piglins.

There are 2 teleportation mechanisms on the server, both can trigger this crash:
1 - summon an armorstand, execute a function as that armorstand which sets its Pos field and then teleports the player in question to itself.
2 - teleport to another player directly through functions.

When crashing, the server takes takes 60 seconds until it times out. I have attached 4 de-obfuscated crash reports. I can provide more if necessary, but they all follow a similar pattern.

Edit: Was able to reproduce it. https://www.youtube.com/watch?v=DFa4wSobUY8

Linked issues

relates to 1

MC-202249 Angering passive mobs in new nether chunks very far away from previously generated chunks, then entering a nether portal causes server to completely freeze Resolved

Attachments

crash-2020-11-05_08.46.03-server.txt

crash-2020-11-05_08.57.57-server.txt

crash-2020-12-13_18.37.43-server.txt

crash-2020-12-24_17.39.33-server.txt

deobfuscated_crash-2020-11-05_08.46.03-server.txt.txt

deobfuscated_crash-2020-11-05_08.57.57-server.txt.txt

deobfuscated_crash-2020-12-13_18.37.43-server.txt.txt

deobfuscated_crash-2020-12-24_17.39.33-server.txt.txt

Comments 14

[Mod] violine1101 2020-12-28T20:00:12Z

The server shuts down automatically because of too much lag.

We do not have enough information to find the cause of this issue.

While the lag occurs, please run /debug start, wait a while and then run /debug stop in order to create a debug profile. Afterwards, run /debug report.

If you do not have the permission to run these commands, open your world to LAN and enable cheats. If you're on a server, make sure that you're a server operator in order to execute these commands.

Then, please attach the profile results found in [minecraft/debug/profile-results-<DATE>.txt|https://minecrafthopper.net/help/finding-minecraft-data-folder/], as well as the debug report found in [minecraft/debug/debug-report-<DATE>.zip|https://minecrafthopper.net/help/finding-minecraft-data-folder/] here.

_{This issue is being temporarily closed as}_{Awaiting Response}_{. Once the requested information has been delivered, the report will be reopened automatically.}

Quick Links:
📓 Bug Tracker Guidelines – 💬 Community Support – 📧 Mojang Support
📓 Project Summary – ✍️ Feedback and Suggestions – 📖 Game Wiki

Thaodan 2020-12-28T22:11:08Z

What on earth are you talking about? No it does not shut down because of too much lag. The server runs perfectly fine until it suddenly stops responding and the watchdog kills it exactly 60 seconds after the teleport.

In two of the crashes I've attached there is a single person online running a run-of-the-mill gold farm, the TPS was most certainly at 20 until the second the player teleports away.

anthony cicinelli 2020-12-28T22:25:14Z

Does MC-63590 describe your issue?

Thaodan 2020-12-28T22:39:11Z

No. It doesn't. Just read the crash dump: they all have an almost identical stack trace with the commonality that a zombified piglin tries to pathfind and that function call takes more than 60 seconds to complete, exceeding the watchdog timer.

Linking some other random report does not help, and this is frankly starting to feel insulting...

[Mod] violine1101 2020-12-28T23:17:55Z

Does the issue happen without having any datapacks enabled? If not, please attach the affected data pack. It has probably some error that causes the function to loop indefinitely.

4 more comments

Thaodan 2020-12-29T00:10:13Z

Read. The. Crash. Dump.

I've gone the extra mile to de-obfuscate it, yet you keep asking questions you could rule out by looking at it for a minute.

If every time the watchdog kills the server is during the pathfinding of a zombified piglin it's clearly not the datapack that's at fault here, is it?

The functions in charge of teleporting contain a simple 'tp @s ~ ~ ~' executed at the right position and it gets called through #minecraft:tick. It does not mess with any other entities nor force-load chunks.

Now please stop insulting my intelligence or wasting my time by not bothering to look at the crash dump.

[Mod] violine1101 2020-12-29T00:19:24Z

Your crash reports don't suffice to be able to reproduce this issue, and your description doesn't either. Closed as incomplete.

Please take a look at the Bug Tracker Guidelines before creating further bug reports.

pokechu22 2020-12-29T04:33:46Z

I've taken a look at the crash dump. Thank you for trying to be helpful by deobfuscating it... but you actually made it a bit more confusing. Looking at the bottom of the stacktrace, there is this:

at net.minecraft.server.MinecraftServer.tickChildren(MinecraftServer.java:871)
	at net.minecraft.server.dedicated.DedicatedServer.tickChildren(DedicatedServer.java:312)
	at net.minecraft.server.MinecraftServer.tickServer(MinecraftServer.java:811)
	at net.minecraft.server.MinecraftServer.publishServer(MinecraftServer.java:811)
	at net.minecraft.server.MinecraftServer.isSingleplayerOwner(MinecraftServer.java:811)
	at net.minecraft.server.MinecraftServer.runServer(MinecraftServer.java:670)
	at net.minecraft.server.MinecraftServer.spin(MinecraftServer.java:257)
	at net.minecraft.server.MinecraftServer.publishServer(MinecraftServer.java:257)
	at net.minecraft.server.MinecraftServer.isSingleplayerOwner(MinecraftServer.java:257)
	at net.minecraft.server.MinecraftServer.lambda$spin$0(MinecraftServer.java:257)

which just doesn't make any sense at all (isSingleplayerOwner is on both lines 257 and 811, and there are multiple functions on lines 257 and 811 as well somehow?) I'm not even sure how it ended up in this state (possibly incorrect handling of overloaded obfuscated names; multiple functions named a exist and are disambiguated by the signature or the line number); as far as I can tell those lines should be something like this:

at net.minecraft.server.MinecraftServer.a(SourceFile:811)
        at net.minecraft.server.MinecraftServer.w(SourceFile:670)
        at net.minecraft.server.MinecraftServer.a(SourceFile:257)
        at net.minecraft.server.MinecraftServer$$Lambda$3311/1397283620.run(Unknown Source)

Based on what I can understand from your description, what you're trying to describe is a mob trying to pathfind to a player that's teleported a long distance away, causing the server to hang. The crash report isn't inconsistent with that (the top is at least consistent with getChunk being called repeatedly, which I think could happen if pathfinding goes through unloaded chunks, though I'm not sure of that). I would expect the game to cancel pathfinding if the distance is too large, but perhaps that doesn't happen with however you've set it up.

This vaugely reminds me of MC-149563, where entities will still try to pathfind after changing dimensions (though that's not an issue I've reproduced myself).

The link to MC-63590 and a request for a profile report is standard for watchdog crashes, as usually the crash itself is not informative (a random part of the tick) and it's just the server being too laggy. In this case, though, since you've got more or less the same report each time, it does seem like it's an actual hang in one part of the code (or being stuck in chunk loading due to it being repeatedly called).

Can you attach a non-deobfuscated crash report, please? Also, when the crash happened, do you know if the area that was teleported from was some place that would remain loaded afterwards? (Possibly due to other players, but in 2 of your reports you have Player Count: 1 / 50 so it can't require a second player to keep the area loaded.)

Thaodan 2020-12-29T15:02:22Z

I have attached the same crash dumps in non-deobfuscated form now. And yes, that's exactly what it looks like.

Yes that description is correct; my guess was that either the entity doesn't do a dimension check or it tries to pathfind to the player's coordinates but in the wrong dimension or is in some kind of dead-lock, but since I'm not familiar with the source code I didn't want to start theory-crafting.

MC-149563 may be related, but it's hard to tell as the events leading up to it are quite different.

I've asked some of the players that were online as the crashes occurred. I can confirm that this crash has happened at times when the area left behind was being loaded by another player as well as when there was no-one else around. The mob farms that triggered this crash are all in areas that are not permanently loaded for performance reason, so regular unloading should occur eventually.

In addition, at least one of the crashes was apparently triggered by using a regular nether portal, which I was not aware of until now, but without knowing when that was the case I can't pull up the exact crash report. So I'd take that with a grain of salt.

Also of note: the players involved sometimes see the area they wanted to go to and sometimes the terrain isn't able to load in in time before the crash, so the time-frame between teleporting away and the start of the hang-up must be quite short.

I understand that you must get a lot of people seeing "Watchdog Error" and immediately posting an unhelpful bug report on it, I just didn't expect to still get dismissive questions 3 comments in.

pokechu22 2020-12-29T21:47:53Z

Deobfuscating

[media]

, I get this:

java.lang.Error: Watchdog
	at sun.misc.Unsafe.park(Native Method)
	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	at net.minecraft.util.thread.BlockableEventLoop.waitForTasks(SourceFile:139)
	at net.minecraft.util.thread.BlockableEventLoop.managedBlock(SourceFile:129)
	at net.minecraft.server.level.ServerChunkCache.getChunk(SourceFile:141)
	at net.minecraft.world.level.Level.getChunk(SourceFile:209)
	at net.minecraft.world.level.LevelReader.getChunk(SourceFile:128)
	at net.minecraft.world.level.Level.getChunk(SourceFile:204)
	at net.minecraft.world.level.Level.getBlockState(SourceFile:408)
	at net.minecraft.world.level.BlockGetter.lambda$clip$0(SourceFile:59)
	at net.minecraft.world.level.BlockGetter$$Lambda$4112/1916329321.apply(Unknown Source)
	at net.minecraft.world.level.BlockGetter.traverseBlocks(SourceFile:181)
	at net.minecraft.world.level.BlockGetter.clip(SourceFile:58)
	at net.minecraft.world.entity.LivingEntity.canSee(SourceFile:2717)
	at net.minecraft.world.entity.ai.sensing.Sensing.canSee(SourceFile:32)
	at net.minecraft.world.entity.ai.goal.MeleeAttackGoal.tick(SourceFile:112)
	at net.minecraft.world.entity.ai.goal.ZombieAttackGoal.tick(SourceFile:28)
	at net.minecraft.world.entity.ai.goal.WrappedGoal.tick(SourceFile:55)
	at net.minecraft.world.entity.ai.goal.GoalSelector$$Lambda$3810/1313955901.accept(Unknown Source)
	at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184)
	at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:175)
	at java.util.Iterator.forEachRemaining(Iterator.java:116)
	at java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1801)
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:482)
	at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:472)
	at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151)
	at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174)
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:418)
	at net.minecraft.world.entity.ai.goal.GoalSelector.tick(SourceFile:88)
	at net.minecraft.world.entity.Mob.serverAiStep(SourceFile:736)
	at net.minecraft.world.entity.LivingEntity.aiStep(SourceFile:2508)
	at net.minecraft.world.entity.Mob.aiStep(SourceFile:542)
	at net.minecraft.world.entity.monster.Monster.aiStep(SourceFile:43)
	at net.minecraft.world.entity.monster.Zombie.aiStep(SourceFile:260)
	at net.minecraft.world.entity.LivingEntity.tick(SourceFile:2254)
	at net.minecraft.world.entity.Mob.tick(SourceFile:342)
	at net.minecraft.world.entity.monster.Zombie.tick(SourceFile:233)
	at net.minecraft.server.level.ServerLevel.tickNonPassenger(SourceFile:621)
	at net.minecraft.server.level.ServerLevel$$Lambda$3788/19259337.accept(Unknown Source)
	at net.minecraft.world.level.Level.guardEntityTick(SourceFile:561)
	at net.minecraft.server.level.ServerLevel.tick(SourceFile:411)
	at net.minecraft.server.MinecraftServer.tickChildren(SourceFile:871)
	at net.minecraft.server.dedicated.DedicatedServer.tickChildren(SourceFile:312)
	at net.minecraft.server.MinecraftServer.tickServer(SourceFile:811)
	at net.minecraft.server.MinecraftServer.runServer(SourceFile:670)
	at net.minecraft.server.MinecraftServer.spin(SourceFile:257)
	at net.minecraft.server.MinecraftServer$$Lambda$3346/1771305569.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)

[media]

is the same, while

[media]

and

[media]

are slightly different (they're missing ZombieAttackGoal.tick and Zombie.tick, and have EnderMan.aiStep (bdg.k) instead of Zombie.aiStep). But they both share MeleeAttackGoal, which makes sense (ZombieAttackGoal is a subclass of it). Note that Zombie.tick showing up is consistent with it being zombified piglen, as ZombifiedPiglin subclasses Zombie and doesn't have its own tick or aiStep.

MeleeAttackGoal.tick first checks if the attacking entity can see its target. It does this through Sensing.canSee, which calls LivingEntity.canSee which performs a ray-trace. Sensing does appear to have some form of caching, but it looks like it's cleared every tick. The actual ray-tracing doesn't seem to have any dimension checks (it always uses the attacker's world), nor does it make some kind of sanity check as to the distance between entities; based on the crash reports, it looks like this ray-tracing is able to load chunks. MeleeAttackGoal.tick does check the distance between entities, but only uses it to update a counter (ticksUntilNextPathRecalculation) for performing pathfinding and still performs the ray-trace each tick. The path-finding is much more expensive compared to the ray-trace, but if either are loading chunks, it's still super expensive, and I don't see a reason why it shouldn't check the counter first. Checking the counter first wouldn't solve this problem, but it would still reduce the number of ray-traces.

I'm guessing that the following are needed to reproduce this bug:

A large number of mobs with the ability to agro on a player, even if they can't pathfind to them (i.e. the mob farm must store mobs in such a way that they can see the player; no dropping them onto a slab where you attack them from below out of sight).
A teleportation destination where a ray-trace from the mob's eyes to the player's coordinates doesn't immediately hit an obstruction (and furthermore goes into unloaded chunks). For something in the nether, this probably means a farm above a large lava lake, along with a holding pen that doesn't obstruct the mob's eyes.
A situation in which the mobs will stay loaded even though the player has teleported away, or at least will perform a single tick after the player has teleported away (I don't know the details of chunk loading or ticking, so I can't say whether this is rare or common).

I think that placing a large number of mobs in spawn chunks in a superflat world, letting them agro, and then teleporting away will be enough to reproduce this issue. I'll test it, but for now, this issue is at least plausible enough for me to re-open it.

Some additional questions:

When players teleport, are they going from the nether to the overworld? Or to another location in the nether? About how far away would these distances be? (Similarly, for the nether portal case, how far away is the corresponding portal in the overworld? It'd be about 7 times the coordinates in the nether, I reckon.)
Am I correct about mobs having a wide line of sight from wherever the farm stores them?

Thaodan 2020-12-30T01:35:38Z

Tested it according to instructions and it does work (https://www.youtube.com/watch?v=DFa4wSobUY8). It's a superflat world opened in LAN with a second player loading the area, as I found that /forceload does not seem to be enough to trigger it, or at least with a much lower probability.

As you can see in the footage the 'Client Chunk Cache' counts up rapidly as it not only tries to load the chunks in the path to the player, but actively generates missing ones. Since it will happily do this forever though, I don't get a crash-dump using this setup, however it does trigger consistently.

pine1needle 2021-01-04T07:06:49Z

This might be the same issue as MC-202249?

Thaodan 2021-01-05T17:25:26Z

I'm pretty confident it's the same issue, yes.

Creeperlover2001 2021-05-20T23:02:18Z

Yeah, i do think it's the same.. The issue only occurs at very high distances from 0, 0.