[MC-227202] Slow world loading after 1.17-pre3

After upgrading one of my dedicated servers to 1.17-pre3 the world took significantly longer to load on server start up. The preparing spawn area phase counted all the way up to one hundred and threw an exception which was not the behavior on 1.17-pre2 and below. Before the console would output zero percent a few times and jump to something like 7 percent before stating that the world was done loading and displayed the time it took. In 1.17-pre2 the server took 2.644 seconds to load and in pre3 and pre4 it took 8.98 seconds and threw the following exception between 1% and 2% of the preparing spawn phase.

[Server thread/ERROR]: No key size in MapLike[{extra_size:2,min_size:1,type:"minecraft:column_placer"}]
[Server thread/ERROR]: Exception loading structure piece with id minecraft:jigsaw
java.lang.IllegalStateException: Invalid pool element found
	at dbf.k(SourceFile:54) ~[server.jar:?]
	at java.util.Optional.orElseThrow(Optional.java:403) ~[?:?]
	at dbf.<init>(SourceFile:54) ~[server.jar:?]
	at cuc.a(SourceFile:151) ~[server.jar:?]
	at cni.a(SourceFile:415) ~[server.jar:?]
	at cni.a(SourceFile:175) ~[server.jar:?]
	at abe.l(SourceFile:511) ~[server.jar:?]
	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1764) ~[?:?]
	at aqu.c(SourceFile:151) ~[server.jar:?]
	at abp$a.c(SourceFile:527) ~[server.jar:?]
	at aqu.z(SourceFile:125) ~[server.jar:?]
	at abp$a.z(SourceFile:536) ~[server.jar:?]
	at abp.d(SourceFile:279) ~[server.jar:?]
	at net.minecraft.server.MinecraftServer.bg(SourceFile:771) ~[server.jar:?]
	at net.minecraft.server.MinecraftServer.z(SourceFile:759) ~[server.jar:?]
	at aqu.c(SourceFile:134) ~[server.jar:?]
	at net.minecraft.server.MinecraftServer.y(SourceFile:744) ~[server.jar:?]
	at net.minecraft.server.MinecraftServer.b(SourceFile:525) ~[server.jar:?]
	at net.minecraft.server.MinecraftServer.e_(SourceFile:357) ~[server.jar:?]
	at aas.e(SourceFile:183) ~[server.jar:?]
	at net.minecraft.server.MinecraftServer.x(SourceFile:665) ~[server.jar:?]
	at net.minecraft.server.MinecraftServer.a(SourceFile:274) ~[server.jar:?]
	at java.lang.Thread.run(Thread.java:831) [?:?]
[Server thread/ERROR]: No key size in MapLike[{extra_size:2,min_size:1,type:"minecraft:column_placer"}]
[Server thread/ERROR]: Exception loading structure piece with id minecraft:jigsaw
java.lang.IllegalStateException: Invalid pool element found
	at dbf.k(SourceFile:54) ~[server.jar:?]
	at java.util.Optional.orElseThrow(Optional.java:403) ~[?:?]
	at dbf.<init>(SourceFile:54) ~[server.jar:?]
	at cuc.a(SourceFile:151) ~[server.jar:?]
	at cni.a(SourceFile:415) ~[server.jar:?]
	at cni.a(SourceFile:175) ~[server.jar:?]
	at abe.l(SourceFile:511) ~[server.jar:?]
	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1764) ~[?:?]
	at aqu.c(SourceFile:151) ~[server.jar:?]
	at abp$a.c(SourceFile:527) ~[server.jar:?]
	at aqu.z(SourceFile:125) ~[server.jar:?]
	at abp$a.z(SourceFile:536) ~[server.jar:?]
	at abp.d(SourceFile:279) ~[server.jar:?]
	at net.minecraft.server.MinecraftServer.bg(SourceFile:771) ~[server.jar:?]
	at net.minecraft.server.MinecraftServer.z(SourceFile:759) ~[server.jar:?]
	at aqu.c(SourceFile:134) ~[server.jar:?]
	at net.minecraft.server.MinecraftServer.y(SourceFile:744) ~[server.jar:?]
	at net.minecraft.server.MinecraftServer.b(SourceFile:525) ~[server.jar:?]
	at net.minecraft.server.MinecraftServer.e_(SourceFile:357) ~[server.jar:?]
	at aas.e(SourceFile:183) ~[server.jar:?]
	at net.minecraft.server.MinecraftServer.x(SourceFile:665) ~[server.jar:?]
	at net.minecraft.server.MinecraftServer.a(SourceFile:274) ~[server.jar:?]
	at java.lang.Thread.run(Thread.java:831) [?:?]

Linked issues

relates to

MC-227945 "Exception loading structure piece" and "No key" error spam after upgrading a world to 1.17 and exploring chunks

Comments

violine1101 2021-06-03T15:59:04Z

Just to confirm, the same thing still happens in 1.17-pre4?

migrated 2021-06-03T19:46:41Z

Yes it still occurs in pre4 and pre5, but the issue is no longer present if I downgrade the server to pre2 or below.

slicedlime 2021-06-04T06:58:07Z

Do you have any world generation datapacks enabled?

migrated 2021-06-04T10:27:15Z

No, I have left the world to generate with what the default generation for the snapshots. I also skipped updating to the snapshots with the noise caves and world height changes so I haven’t touched anything with the world nbt or used the 1.18 terrain on this server.

migrated 2021-06-04T11:57:12Z

was testing 1.18 gen datapacks also lagging

migrated 2021-06-04T13:22:47Z

On single player might I add

ampolive 2021-06-04T19:16:45Z

Given that this started in pre3, could this be caused by the attempted fix of MC-224893?

ampolive 2021-06-08T22:21:19Z

The exception thrown in this issue is similar to MC-227945.

migrated 2021-06-09T16:45:15Z

I have a world from 1.16 that is throwing identical warnings as well. No issues on 1.16, however on 1.17 it sends this warning, but otherwise appears to run correctly. No apparent lag or other issues.

ampolive 2021-06-09T20:07:48Z

This happens in my world too, only difference is that it lags as well. The log also spams these error messages:

Exception loading structure piece with id minecraft:jigsaw
java.lang.IllegalStateException: Invalid call to EmtyPoolElement.getBoundingBox, filter me!
Invalid bounding box data, inverted bounds for: daq{minX=2147483647, minY=2147483647, minZ=2147483647, maxX=-2147483648, maxY=-2147483648, maxZ=-2147483648}

I don't know if it is a different issue.

migrated 2021-06-10T20:29:59Z

Get flooding with those as well.

It happens in a world that got updated since 1.14.

migrated 2021-07-09T05:29:10Z

Having the same issue with a long-time world I started with 1.7. Load time in 1.16.5 was fairly modest but when I updated to 1.17 it shot up probably a good 3x - 4x.

I also see those same errors in the log file. Though even if I load the world in an area where those errors don't show up the load time is still very slow. I'm tempted to try 1.17-pre2 and see if that is faster.

migrated 2021-09-29T22:45:23Z

I just made a copy of the effected world file and ran it on a fresh 21w39a vanilla server and the error in the log about column_placer feature is no longer present. Though there was still a major regression in load times even after first launch. The average start time is about ~17 seconds now; however, after using the --forceUpgrade option when starting the server it has returned to an average of ~7 seconds. That is still worse than 1.17-pre2 though a major improvement from the first few runs after updating to 21w39a. Can someone else that has this issue check if the error in the log is gone? If so I will update this ticket to state the log error has been fixed but not the performance regression.

ampolive 2021-09-29T22:55:13Z

The "No key" error seems to no longer be present, but the errors in this comment persist.

ampolive 2021-10-07T15:44:52Z

Can confirm in 21w40a.

ampolive 2021-10-13T17:26:58Z

Can confirm in 21w41a.

ampolive 2021-10-20T16:35:53Z

Can confirm in 21w42a.

ampolive 2021-10-27T17:01:32Z

Can confirm in 21w43a, and it has gotten significantly worse with the introduction of the chunk blending algorithm.

migrated 2021-11-04T03:55:09Z

World loading time is something like 5x the time it took pre 1.17

(your results may vary....mine have been garbage)

ampolive 2021-11-11T18:50:34Z

Can confirm in 1.18 Pre-release 1.

ampolive 2021-11-17T16:54:56Z

Can confirm in 1.18 Pre-release 3.