Paper/patches/server/0343-Add-debug-for-sync-chunk-loads.patch

340 lines
14 KiB
Diff
Raw Normal View History

From 0000000000000000000000000000000000000000 Mon Sep 17 00:00:00 2001
From: Spottedleaf <Spottedleaf@users.noreply.github.com>
Date: Fri, 19 Jul 2019 03:29:14 -0700
Subject: [PATCH] Add debug for sync chunk loads
This patch adds a tool to find calls to getChunkAt which would load
chunks, however it must be enabled by setting the startup flag
-Dpaper.debug-sync-loads=true
- To get a debug log for sync loads, the command is
/paper syncloadinfo
- To clear clear the currently stored sync load info, use
/paper syncloadinfo clear
diff --git a/src/main/java/com/destroystokyo/paper/io/SyncLoadFinder.java b/src/main/java/com/destroystokyo/paper/io/SyncLoadFinder.java
new file mode 100644
index 0000000000000000000000000000000000000000..0bb4aaa546939b67a5d22865190f30478a9337c1
--- /dev/null
+++ b/src/main/java/com/destroystokyo/paper/io/SyncLoadFinder.java
@@ -0,0 +1,175 @@
+package com.destroystokyo.paper.io;
+
+import com.google.gson.JsonArray;
+import com.google.gson.JsonObject;
+import com.mojang.datafixers.util.Pair;
+import it.unimi.dsi.fastutil.longs.Long2IntMap;
+import it.unimi.dsi.fastutil.longs.Long2IntOpenHashMap;
+import it.unimi.dsi.fastutil.objects.Object2ObjectOpenHashMap;
+
+import java.util.ArrayList;
+import java.util.List;
+import java.util.Map;
+import java.util.WeakHashMap;
+import net.minecraft.world.level.Level;
+
+public class SyncLoadFinder {
+
+ public static final boolean ENABLED = Boolean.getBoolean("paper.debug-sync-loads");
+
+ private static final WeakHashMap<Level, Object2ObjectOpenHashMap<ThrowableWithEquals, SyncLoadInformation>> SYNC_LOADS = new WeakHashMap<>();
+
+ private static final class SyncLoadInformation {
+
+ public int times;
+
+ public final Long2IntOpenHashMap coordinateTimes = new Long2IntOpenHashMap();
+ }
+
+ public static void clear() {
+ SYNC_LOADS.clear();
+ }
+
+ public static void logSyncLoad(final Level world, final int chunkX, final int chunkZ) {
+ if (!ENABLED) {
+ return;
+ }
+
+ final ThrowableWithEquals stacktrace = new ThrowableWithEquals(Thread.currentThread().getStackTrace());
+
+ SYNC_LOADS.compute(world, (final Level keyInMap, Object2ObjectOpenHashMap<ThrowableWithEquals, SyncLoadInformation> map) -> {
+ if (map == null) {
+ map = new Object2ObjectOpenHashMap<>();
+ }
+
+ map.compute(stacktrace, (ThrowableWithEquals keyInMap0, SyncLoadInformation valueInMap) -> {
+ if (valueInMap == null) {
+ valueInMap = new SyncLoadInformation();
+ }
+
+ ++valueInMap.times;
+
+ valueInMap.coordinateTimes.compute(IOUtil.getCoordinateKey(chunkX, chunkZ), (Long keyInMap1, Integer valueInMap1) -> {
+ return valueInMap1 == null ? Integer.valueOf(1) : Integer.valueOf(valueInMap1.intValue() + 1);
+ });
+
+ return valueInMap;
+ });
+
+ return map;
+ });
+ }
+
+ public static JsonObject serialize() {
+ final JsonObject ret = new JsonObject();
+
+ final JsonArray worldsData = new JsonArray();
+
+ for (final Map.Entry<Level, Object2ObjectOpenHashMap<ThrowableWithEquals, SyncLoadInformation>> entry : SYNC_LOADS.entrySet()) {
+ final Level world = entry.getKey();
+
+ final JsonObject worldData = new JsonObject();
+
+ worldData.addProperty("name", world.getWorld().getName());
+
+ final List<Pair<ThrowableWithEquals, SyncLoadInformation>> data = new ArrayList<>();
+
+ entry.getValue().forEach((ThrowableWithEquals stacktrace, SyncLoadInformation times) -> {
+ data.add(new Pair<>(stacktrace, times));
+ });
+
+ data.sort((Pair<ThrowableWithEquals, SyncLoadInformation> pair1, Pair<ThrowableWithEquals, SyncLoadInformation> pair2) -> {
+ return Integer.compare(pair2.getSecond().times, pair1.getSecond().times); // reverse order
+ });
+
+ final JsonArray stacktraces = new JsonArray();
+
+ for (Pair<ThrowableWithEquals, SyncLoadInformation> pair : data) {
+ final JsonObject stacktrace = new JsonObject();
+
+ stacktrace.addProperty("times", pair.getSecond().times);
+
+ final JsonArray traces = new JsonArray();
+
+ for (StackTraceElement element : pair.getFirst().stacktrace) {
+ traces.add(String.valueOf(element));
+ }
+
+ stacktrace.add("stacktrace", traces);
+
+ final JsonArray coordinates = new JsonArray();
+
+ for (Long2IntMap.Entry coordinate : pair.getSecond().coordinateTimes.long2IntEntrySet()) {
+ final long key = coordinate.getLongKey();
+ final int times = coordinate.getIntValue();
+ coordinates.add("(" + IOUtil.getCoordinateX(key) + "," + IOUtil.getCoordinateZ(key) + "): " + times);
+ }
+
+ stacktrace.add("coordinates", coordinates);
+
+ stacktraces.add(stacktrace);
+ }
+
+
+ worldData.add("stacktraces", stacktraces);
+ worldsData.add(worldData);
+ }
+
+ ret.add("worlds", worldsData);
+
+ return ret;
+ }
+
+ static final class ThrowableWithEquals {
+
+ private final StackTraceElement[] stacktrace;
+ private final int hash;
+
+ public ThrowableWithEquals(final StackTraceElement[] stacktrace) {
+ this.stacktrace = stacktrace;
+ this.hash = ThrowableWithEquals.hash(stacktrace);
+ }
+
+ public static int hash(final StackTraceElement[] stacktrace) {
+ int hash = 0;
+
+ for (int i = 0; i < stacktrace.length; ++i) {
+ hash *= 31;
+ hash += stacktrace[i].hashCode();
+ }
+
+ return hash;
+ }
+
+ @Override
+ public int hashCode() {
+ return this.hash;
+ }
+
+ @Override
+ public boolean equals(final Object obj) {
+ if (obj == null || obj.getClass() != this.getClass()) {
+ return false;
+ }
+
+ final ThrowableWithEquals other = (ThrowableWithEquals)obj;
+ final StackTraceElement[] otherStackTrace = other.stacktrace;
+
+ if (this.stacktrace.length != otherStackTrace.length || this.hash != other.hash) {
+ return false;
+ }
+
+ if (this == obj) {
+ return true;
+ }
+
+ for (int i = 0; i < this.stacktrace.length; ++i) {
+ if (!this.stacktrace[i].equals(otherStackTrace[i])) {
+ return false;
+ }
+ }
+
+ return true;
+ }
+ }
+}
diff --git a/src/main/java/io/papermc/paper/command/PaperCommand.java b/src/main/java/io/papermc/paper/command/PaperCommand.java
2023-09-22 04:31:59 +02:00
index 830978f3409888302ab857161628cee5869efa8f..43573b5ef76c8bb42411c3707cb13d90d531b905 100644
--- a/src/main/java/io/papermc/paper/command/PaperCommand.java
+++ b/src/main/java/io/papermc/paper/command/PaperCommand.java
2023-09-22 04:31:59 +02:00
@@ -39,6 +39,7 @@ public final class PaperCommand extends Command {
commands.put(Set.of("version"), new VersionCommand());
2023-02-19 15:57:10 +01:00
commands.put(Set.of("dumpplugins"), new DumpPluginsCommand());
commands.put(Set.of("fixlight"), new FixLightCommand());
+ commands.put(Set.of("syncloadinfo"), new SyncLoadInfoCommand());
return commands.entrySet().stream()
.flatMap(entry -> entry.getKey().stream().map(s -> Map.entry(s, entry.getValue())))
diff --git a/src/main/java/io/papermc/paper/command/subcommands/SyncLoadInfoCommand.java b/src/main/java/io/papermc/paper/command/subcommands/SyncLoadInfoCommand.java
new file mode 100644
index 0000000000000000000000000000000000000000..95d6022c9cfb2e36ec5a71be6e34354027c2ec08
--- /dev/null
+++ b/src/main/java/io/papermc/paper/command/subcommands/SyncLoadInfoCommand.java
@@ -0,0 +1,88 @@
+package io.papermc.paper.command.subcommands;
+
+import com.destroystokyo.paper.io.SyncLoadFinder;
+import com.google.gson.JsonObject;
+import com.google.gson.internal.Streams;
+import com.google.gson.stream.JsonWriter;
+import io.papermc.paper.command.CommandUtil;
+import io.papermc.paper.command.PaperSubcommand;
+import java.io.File;
+import java.io.FileOutputStream;
+import java.io.PrintStream;
+import java.io.StringWriter;
+import java.nio.charset.StandardCharsets;
+import java.time.LocalDateTime;
+import java.time.format.DateTimeFormatter;
+import java.util.List;
+
+import net.kyori.adventure.text.event.ClickEvent;
+import net.kyori.adventure.text.event.HoverEvent;
+import net.minecraft.server.MinecraftServer;
+import org.bukkit.command.CommandSender;
+import org.checkerframework.checker.nullness.qual.NonNull;
+import org.checkerframework.framework.qual.DefaultQualifier;
+
+import static net.kyori.adventure.text.Component.text;
+import static net.kyori.adventure.text.format.NamedTextColor.GRAY;
+import static net.kyori.adventure.text.format.NamedTextColor.GREEN;
+import static net.kyori.adventure.text.format.NamedTextColor.RED;
+import static net.kyori.adventure.text.format.NamedTextColor.WHITE;
+
+@DefaultQualifier(NonNull.class)
+public final class SyncLoadInfoCommand implements PaperSubcommand {
+ @Override
+ public boolean execute(final CommandSender sender, final String subCommand, final String[] args) {
+ this.doSyncLoadInfo(sender, args);
+ return true;
+ }
+
+ @Override
+ public List<String> tabComplete(final CommandSender sender, final String subCommand, final String[] args) {
+ return CommandUtil.getListMatchingLast(sender, args, "clear");
+ }
+
+ private static final DateTimeFormatter FORMATTER = DateTimeFormatter.ofPattern("yyyy-MM-dd_HH.mm.ss");
+
+ private void doSyncLoadInfo(final CommandSender sender, final String[] args) {
+ if (!SyncLoadFinder.ENABLED) {
+ String systemFlag = "-Dpaper.debug-sync-loads=true";
+ sender.sendMessage(text().color(RED).append(text("This command requires the server startup flag '")).append(
+ text(systemFlag, WHITE).clickEvent(ClickEvent.copyToClipboard(systemFlag))
+ .hoverEvent(HoverEvent.showText(text("Click to copy the system flag")))).append(
+ text("' to be set.")));
+ return;
+ }
+
+ if (args.length > 0 && args[0].equals("clear")) {
+ SyncLoadFinder.clear();
+ sender.sendMessage(text("Sync load data cleared.", GRAY));
+ return;
+ }
+
+ File file = new File(new File(new File("."), "debug"),
+ "sync-load-info-" + FORMATTER.format(LocalDateTime.now()) + ".txt");
+ file.getParentFile().mkdirs();
+ sender.sendMessage(text("Writing sync load info to " + file, GREEN));
+
+
+ try {
+ final JsonObject data = SyncLoadFinder.serialize();
+
+ StringWriter stringWriter = new StringWriter();
+ JsonWriter jsonWriter = new JsonWriter(stringWriter);
+ jsonWriter.setIndent(" ");
+ jsonWriter.setLenient(false);
+ Streams.write(data, jsonWriter);
+
+ try (
+ PrintStream out = new PrintStream(new FileOutputStream(file), false, StandardCharsets.UTF_8)
+ ) {
+ out.print(stringWriter);
+ }
+ sender.sendMessage(text("Successfully written sync load information!", GREEN));
+ } catch (Throwable thr) {
+ sender.sendMessage(text("Failed to write sync load information! See the console for more info.", RED));
+ MinecraftServer.LOGGER.warn("Error occurred while dumping sync chunk load info", thr);
+ }
+ }
+}
diff --git a/src/main/java/net/minecraft/server/level/ServerChunkCache.java b/src/main/java/net/minecraft/server/level/ServerChunkCache.java
2023-09-22 04:31:59 +02:00
index b6461fdd77895fbeae10e92c76e8799c7e846ac5..7aceefc28f310e704ca8803e95c40ada13718988 100644
--- a/src/main/java/net/minecraft/server/level/ServerChunkCache.java
+++ b/src/main/java/net/minecraft/server/level/ServerChunkCache.java
2023-09-22 04:31:59 +02:00
@@ -393,6 +393,7 @@ public class ServerChunkCache extends ChunkSource {
@Nullable
@Override
public ChunkAccess getChunk(int x, int z, ChunkStatus leastStatus, boolean create) {
+ final int x1 = x; final int z1 = z; // Paper - conflict on variable change
if (Thread.currentThread() != this.mainThread) {
return (ChunkAccess) CompletableFuture.supplyAsync(() -> {
return this.getChunk(x, z, leastStatus, create);
@@ -426,6 +427,7 @@ public class ServerChunkCache extends ChunkSource {
Objects.requireNonNull(completablefuture);
if (!completablefuture.isDone()) { // Paper
+ com.destroystokyo.paper.io.SyncLoadFinder.logSyncLoad(this.level, x1, z1); // Paper - sync load info
this.level.timings.syncChunkLoad.startTiming(); // Paper
chunkproviderserver_b.managedBlock(completablefuture::isDone);
2023-09-22 04:31:59 +02:00
this.level.timings.syncChunkLoad.stopTiming(); // Paper
diff --git a/src/main/java/net/minecraft/server/level/ServerLevel.java b/src/main/java/net/minecraft/server/level/ServerLevel.java
2023-09-22 14:33:54 +02:00
index 9bcf1fee8df0186f7355bf37ba7c39553bdbf1d0..79229f3563cc642568487ea92840c8753c536240 100644
--- a/src/main/java/net/minecraft/server/level/ServerLevel.java
+++ b/src/main/java/net/minecraft/server/level/ServerLevel.java
2023-09-22 04:31:59 +02:00
@@ -416,6 +416,13 @@ public class ServerLevel extends Level implements WorldGenLevel {
this.getCraftServer().addWorld(this.getWorld()); // CraftBukkit
Rewrite chunk system (#8177) Patch documentation to come Issues with the old system that are fixed now: - World generation does not scale with cpu cores effectively. - Relies on the main thread for scheduling and maintaining chunk state, dropping chunk load/generate rates at lower tps. - Unreliable prioritisation of chunk gen/load calls that block the main thread. - Shutdown logic is utterly unreliable, as it has to wait for all chunks to unload - is it guaranteed that the chunk system is in a state on shutdown that it can reliably do this? Watchdog shutdown also typically failed due to thread checks, which is now resolved. - Saving of data is not unified (i.e can save chunk data without saving entity data, poses problems for desync if shutdown is really abnormal. - Entities are not loaded with chunks. This caused quite a bit of headache for Chunk#getEntities API, but now the new chunk system loads entities with chunks so that they are ready whenever the chunk loads in. Effectively brings the behavior back to 1.16 era, but still storing entities in their own separate regionfiles. The above list is not complete. The patch documentation will complete it. New chunk system hard relies on starlight and dataconverter, and most importantly the new concurrent utilities in ConcurrentUtil. Some of the old async chunk i/o interface (i.e the old file io thread reroutes _some_ calls to the new file io thread) is kept for plugin compat reasons. It will be removed in the next major version of minecraft. The old legacy chunk system patches have been moved to the removed folder in case we need them again.
2022-09-26 10:02:51 +02:00
}
2023-06-08 00:12:41 +02:00
+ // Paper start
+ @Override
+ public boolean hasChunk(int chunkX, int chunkZ) {
+ return this.getChunkSource().getChunkAtIfLoadedImmediately(chunkX, chunkZ) != null;
+ }
+ // Paper end
2023-06-08 00:12:41 +02:00
+
/** @deprecated */
@Deprecated
@VisibleForTesting