[MC-145744] Villager AI (POI detection) pegs CPU at 100%

Fine-Structure is a casual-play 1.13.2 server that we use for testing purposes. Loading it up into 19w11a exposes a new severe performance problem. One thread dominates the CPU time and pegs the CPU at 100%. I used async-profiler to analyze this, and a screenshot is attached. The full profile in HTML form can also be found at "https://www.dropbox.com/s/33lqat9x3yzkdny/tree2.html?dl=0".

According to people from the Fabric project, this is villager AI. Rockenroll4life confirmed that there's a new AI engine.

We do have a fair number of villagers in one area. In 1.13.2, there were lag problems due to entity collisions. In 1.14, the collision problem is fixed, but now there's significant lag caused by villager AI processing instead.

Linked issues

is duplicated by 1

MC-155649 Villagers cause high amounts of ping on single player worlds Resolved

relates to 3

MC-138550 High ms ticks in 1.14+, player cannot interact with world normally Resolved

MC-136935 Villager performs "move" even though its impossible - Laggs server Resolved

MC-145772 Large amount of free work sites can cause lag when introducing new villagers Resolved

Attachments

IronDeficiency-Wutax.zip

profile-results-2019-05-13_11.25.18.txt

Screen Shot 2019-03-13 at 3.05.39 PM.png

tree.html

Comments 17

Johnibur 2019-03-15T21:36:21Z

By running the internal debug profiler, you can see that minecraft:villager.ai.newAI.mob tick.brain is now generally leading the tick time.

Timothy Miller 2019-03-27T18:42:59Z

This is still a problem in 19w13a. According to boq, this relates to villager POI detection. I also uploaded a profile (from async-profiler) for 19w13a.

Greg Milson 2019-04-04T14:21:29Z

Still an issue in 19w14a

ProfMobius (Thomas Guimbretiere) 2019-04-05T08:49:17Z

Do you have a test world associated with that trace so we can reproduce the circumstances of the bug ?

Timothy Miller 2019-04-15T19:43:42Z

Hi, Prof,

We do have a test world. I don't want to post a link here due to privacy reasons, but I sent a download link to Boq. Also, feel free to contact me on Discord via EigenCraft (https://discord.gg/AbYpWWJ), and I can send you a link too.

Thanks.

7 more comments

Timothy Miller 2019-04-15T19:50:19Z

Oh, and Adrian has my email address, if you want to contact me that way. Thanks again!

Timothy Miller 2019-04-15T23:56:06Z

Profile from pre-release 2: https://www.dropbox.com/s/vgyi9g5631xxoe8/tree-pre2.html?dl=0

This kind of thing pops up a lot:
[19:52:44] [Server thread/WARN]: Can't keep up! Is the server overloaded? Running 2240ms or 44 ticks behind

The CPU's pegged at 100% on my 4-core server, although it's better than previous versions, where the total CPU load was more than 150% in the best of cases. One thread uses around 85%, while there are lots of other threads using a few percent each.

Timothy Miller 2019-04-16T12:50:39Z

KaptainWutax was kind enough to share his iron farm, and I profiled that too. The hot spot appears to also be in "villager brain" code, net/minecraft/entity/ai/brain/Brain, and deeper down, net/minecraft/entity/ai/brain/task/WanderAroundTask.

This uses excessive CPU for only 156 villagers. To observe this, you need to /tp to 200, 125, -200.

The profile is here: https://www.dropbox.com/s/5b953oe5qe4i3j8/tree-pre2-iron.html?dl=0
I will include the world download as an attachment, if it fits.

Timothy Miller 2019-05-07T16:55:14Z

FYI, this is not at all improved in 1.14.1-pre1. Here's a profile: https://www.dropbox.com/s/z036lp4eq7tzfse/tree-pre1-fs2.html?dl=0

Timothy Miller 2019-05-12T21:49:17Z

I tried profiling in 1.14.1-pre2, and the performance is still bad there too. Here's another profile: https://www.dropbox.com/s/eg0h93swug3yi7o/tree-1141pre2.html?dl=0

Timothy Miller 2019-05-13T12:23:29Z

I just profiled the 1.14.1 release, and CPU load and the profile don't seem any different from what I was seeing in the snapshots. I think this bug should be reopened. Or if we're mistaken about it being POI, we can retitle the bug report or something.

Have a look here: https://www.dropbox.com/s/0v9ieuvabe5rt28/tree-1141.html?dl=0

Timothy Miller 2019-05-13T15:27:34Z

The built-in profiler matches what I'm getting from async-profiler:

[00] tick - 99.95%/99.95%
[01] |   levels - 99.67%/99.67%
[02] |   |   world minecraft:overworld - 99.77%/99.45%
[03] |   |   |   tick - 100.00%/99.45%
[04] |   |   |   |   entities - 90.41%/89.92%
[05] |   |   |   |   |   regular - 95.87%/86.20%
[06] |   |   |   |   |   |   tick - 99.11%/85.44%
[07] |   |   |   |   |   |   |   minecraft:villager - 35.10%/29.99%
[08] |   |   |   |   |   |   |   |   ai - 66.84%/20.05%
[09] |   |   |   |   |   |   |   |   |   newAi - 99.41%/19.93%
[10] |   |   |   |   |   |   |   |   |   |   mob tick - 85.03%/16.95%
[11] |   |   |   |   |   |   |   |   |   |   |   brain - 99.03%/16.78%
[12] |   |   |   |   |   |   |   |   |   |   |   |   unspecified - 97.96%/16.44%

Jason Hsu 2019-05-26T07:29:36Z

Got this issue too. 1.14.1

Timings profiler, for reference this was ~50 villagers vs 637 zombies and the villagers still caused more lag

[media]

Kamil Pigłowski 2019-05-26T14:09:23Z

I can only confirm that as far as I know after many days of testing on my server villagers and pillagers AI is broken and causing enormous resources usage as well as server crashes from time to time.

Johnibur 2019-05-27T12:09:16Z

@unknown Which version are you in?

Kamil Pigłowski 2019-06-10T19:39:42Z

@Johnibur
I'm on 1.14.2

Adrian Östergård 2019-10-02T07:30:18Z

Is this still an issue in 1.14.4 or later?