mirror of
https://github.com/PaperMC/Paper.git
synced 2024-12-30 16:19:03 +01:00
01a13871de
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.
297 lines
15 KiB
Diff
297 lines
15 KiB
Diff
From 0000000000000000000000000000000000000000 Mon Sep 17 00:00:00 2001
|
|
From: Spottedleaf <Spottedleaf@users.noreply.github.com>
|
|
Date: Thu, 26 Mar 2020 21:59:32 -0700
|
|
Subject: [PATCH] Detail more information in watchdog dumps
|
|
|
|
- Dump position, world, velocity, and uuid for currently ticking entities
|
|
- Dump player name, player uuid, position, and world for packet handling
|
|
|
|
diff --git a/src/main/java/net/minecraft/network/Connection.java b/src/main/java/net/minecraft/network/Connection.java
|
|
index 13ab14b1fb3acfd245fbab35f84f5c30c97ed855..9c0c181013d419d1a74f86b5d8cecf83b28925c6 100644
|
|
--- a/src/main/java/net/minecraft/network/Connection.java
|
|
+++ b/src/main/java/net/minecraft/network/Connection.java
|
|
@@ -504,9 +504,15 @@ public class Connection extends SimpleChannelInboundHandler<Packet<?>> {
|
|
PacketListener packetlistener = this.packetListener;
|
|
|
|
if (packetlistener instanceof TickablePacketListener) {
|
|
+ // Paper start - detailed watchdog information
|
|
+ net.minecraft.network.protocol.PacketUtils.packetProcessing.push(this.packetListener);
|
|
+ try { // Paper end - detailed watchdog information
|
|
TickablePacketListener tickablepacketlistener = (TickablePacketListener) packetlistener;
|
|
|
|
tickablepacketlistener.tick();
|
|
+ } finally { // Paper start - detailed watchdog information
|
|
+ net.minecraft.network.protocol.PacketUtils.packetProcessing.pop();
|
|
+ } // Paper start - detailed watchdog information
|
|
}
|
|
|
|
if (!this.isConnected() && !this.disconnectionHandled) {
|
|
diff --git a/src/main/java/net/minecraft/network/protocol/PacketUtils.java b/src/main/java/net/minecraft/network/protocol/PacketUtils.java
|
|
index acfa1907bfc9c29d261cfccc00d65bad9ad1a002..d6f3869f5725c7f081efb7f486f74dbb99d4d005 100644
|
|
--- a/src/main/java/net/minecraft/network/protocol/PacketUtils.java
|
|
+++ b/src/main/java/net/minecraft/network/protocol/PacketUtils.java
|
|
@@ -15,6 +15,24 @@ public class PacketUtils {
|
|
|
|
private static final Logger LOGGER = LogUtils.getLogger();
|
|
|
|
+ // Paper start - detailed watchdog information
|
|
+ public static final java.util.concurrent.ConcurrentLinkedDeque<PacketListener> packetProcessing = new java.util.concurrent.ConcurrentLinkedDeque<>();
|
|
+ static final java.util.concurrent.atomic.AtomicLong totalMainThreadPacketsProcessed = new java.util.concurrent.atomic.AtomicLong();
|
|
+
|
|
+ public static long getTotalProcessedPackets() {
|
|
+ return totalMainThreadPacketsProcessed.get();
|
|
+ }
|
|
+
|
|
+ public static java.util.List<PacketListener> getCurrentPacketProcessors() {
|
|
+ java.util.List<PacketListener> ret = new java.util.ArrayList<>(4);
|
|
+ for (PacketListener listener : packetProcessing) {
|
|
+ ret.add(listener);
|
|
+ }
|
|
+
|
|
+ return ret;
|
|
+ }
|
|
+ // Paper end - detailed watchdog information
|
|
+
|
|
public PacketUtils() {}
|
|
|
|
public static <T extends PacketListener> void ensureRunningOnSameThread(Packet<T> packet, T listener, ServerLevel world) throws RunningOnDifferentThreadException {
|
|
@@ -24,6 +42,8 @@ public class PacketUtils {
|
|
public static <T extends PacketListener> void ensureRunningOnSameThread(Packet<T> packet, T listener, BlockableEventLoop<?> engine) throws RunningOnDifferentThreadException {
|
|
if (!engine.isSameThread()) {
|
|
engine.executeIfPossible(() -> {
|
|
+ packetProcessing.push(listener); // Paper - detailed watchdog information
|
|
+ try { // Paper - detailed watchdog information
|
|
if (MinecraftServer.getServer().hasStopped() || (listener instanceof ServerGamePacketListenerImpl && ((ServerGamePacketListenerImpl) listener).processedDisconnect)) return; // CraftBukkit, MC-142590
|
|
if (listener.getConnection().isConnected()) {
|
|
co.aikar.timings.Timing timing = co.aikar.timings.MinecraftTimings.getPacketTiming(packet); // Paper - timings
|
|
@@ -43,6 +63,12 @@ public class PacketUtils {
|
|
} else {
|
|
PacketUtils.LOGGER.debug("Ignoring packet due to disconnection: {}", packet);
|
|
}
|
|
+ // Paper start - detailed watchdog information
|
|
+ } finally {
|
|
+ totalMainThreadPacketsProcessed.getAndIncrement();
|
|
+ packetProcessing.pop();
|
|
+ }
|
|
+ // Paper end - detailed watchdog information
|
|
|
|
});
|
|
throw RunningOnDifferentThreadException.RUNNING_ON_DIFFERENT_THREAD;
|
|
diff --git a/src/main/java/net/minecraft/server/level/ServerLevel.java b/src/main/java/net/minecraft/server/level/ServerLevel.java
|
|
index ade1478a6e85bad5a168e3ab8ea3b2744cf18dea..204d101c318cf60fd2e31b0d1b84f78f87d2f68d 100644
|
|
--- a/src/main/java/net/minecraft/server/level/ServerLevel.java
|
|
+++ b/src/main/java/net/minecraft/server/level/ServerLevel.java
|
|
@@ -1039,7 +1039,26 @@ public class ServerLevel extends Level implements WorldGenLevel {
|
|
|
|
}
|
|
|
|
+ // Paper start - log detailed entity tick information
|
|
+ // TODO replace with varhandle
|
|
+ static final java.util.concurrent.atomic.AtomicReference<Entity> currentlyTickingEntity = new java.util.concurrent.atomic.AtomicReference<>();
|
|
+
|
|
+ public static List<Entity> getCurrentlyTickingEntities() {
|
|
+ Entity ticking = currentlyTickingEntity.get();
|
|
+ List<Entity> ret = java.util.Arrays.asList(ticking == null ? new Entity[0] : new Entity[] { ticking });
|
|
+
|
|
+ return ret;
|
|
+ }
|
|
+ // Paper end - log detailed entity tick information
|
|
+
|
|
public void tickNonPassenger(Entity entity) {
|
|
+ // Paper start - log detailed entity tick information
|
|
+ io.papermc.paper.util.TickThread.ensureTickThread("Cannot tick an entity off-main");
|
|
+ try {
|
|
+ if (currentlyTickingEntity.get() == null) {
|
|
+ currentlyTickingEntity.lazySet(entity);
|
|
+ }
|
|
+ // Paper end - log detailed entity tick information
|
|
++TimingHistory.entityTicks; // Paper - timings
|
|
// Spigot start
|
|
co.aikar.timings.Timing timer; // Paper
|
|
@@ -1079,7 +1098,13 @@ public class ServerLevel extends Level implements WorldGenLevel {
|
|
this.tickPassenger(entity, entity1);
|
|
}
|
|
// } finally { timer.stopTiming(); } // Paper - timings - move up
|
|
-
|
|
+ // Paper start - log detailed entity tick information
|
|
+ } finally {
|
|
+ if (currentlyTickingEntity.get() == entity) {
|
|
+ currentlyTickingEntity.lazySet(null);
|
|
+ }
|
|
+ }
|
|
+ // Paper end - log detailed entity tick information
|
|
}
|
|
|
|
private void tickPassenger(Entity vehicle, Entity passenger) {
|
|
diff --git a/src/main/java/net/minecraft/world/entity/Entity.java b/src/main/java/net/minecraft/world/entity/Entity.java
|
|
index bdfa91daf69e71e8c2e1e820f14360c567bdeb87..5e211f1df6739433437930116d134326abbf558d 100644
|
|
--- a/src/main/java/net/minecraft/world/entity/Entity.java
|
|
+++ b/src/main/java/net/minecraft/world/entity/Entity.java
|
|
@@ -972,7 +972,42 @@ public abstract class Entity implements Nameable, EntityAccess, CommandSource {
|
|
return this.onGround;
|
|
}
|
|
|
|
+ // Paper start - detailed watchdog information
|
|
+ public final Object posLock = new Object(); // Paper - log detailed entity tick information
|
|
+
|
|
+ private Vec3 moveVector;
|
|
+ private double moveStartX;
|
|
+ private double moveStartY;
|
|
+ private double moveStartZ;
|
|
+
|
|
+ public final Vec3 getMoveVector() {
|
|
+ return this.moveVector;
|
|
+ }
|
|
+
|
|
+ public final double getMoveStartX() {
|
|
+ return this.moveStartX;
|
|
+ }
|
|
+
|
|
+ public final double getMoveStartY() {
|
|
+ return this.moveStartY;
|
|
+ }
|
|
+
|
|
+ public final double getMoveStartZ() {
|
|
+ return this.moveStartZ;
|
|
+ }
|
|
+ // Paper end - detailed watchdog information
|
|
+
|
|
public void move(MoverType movementType, Vec3 movement) {
|
|
+ // Paper start - detailed watchdog information
|
|
+ io.papermc.paper.util.TickThread.ensureTickThread("Cannot move an entity off-main");
|
|
+ synchronized (this.posLock) {
|
|
+ this.moveStartX = this.getX();
|
|
+ this.moveStartY = this.getY();
|
|
+ this.moveStartZ = this.getZ();
|
|
+ this.moveVector = movement;
|
|
+ }
|
|
+ try {
|
|
+ // Paper end - detailed watchdog information
|
|
if (this.noPhysics) {
|
|
this.setPos(this.getX() + movement.x, this.getY() + movement.y, this.getZ() + movement.z);
|
|
} else {
|
|
@@ -1145,6 +1180,13 @@ public abstract class Entity implements Nameable, EntityAccess, CommandSource {
|
|
this.level.getProfiler().pop();
|
|
}
|
|
}
|
|
+ // Paper start - detailed watchdog information
|
|
+ } finally {
|
|
+ synchronized (this.posLock) { // Paper
|
|
+ this.moveVector = null;
|
|
+ } // Paper
|
|
+ }
|
|
+ // Paper end - detailed watchdog information
|
|
}
|
|
|
|
protected boolean isHorizontalCollisionMinor(Vec3 adjustedMovement) {
|
|
@@ -3973,7 +4015,9 @@ public abstract class Entity implements Nameable, EntityAccess, CommandSource {
|
|
}
|
|
|
|
public void setDeltaMovement(Vec3 velocity) {
|
|
+ synchronized (this.posLock) { // Paper
|
|
this.deltaMovement = velocity;
|
|
+ } // Paper
|
|
}
|
|
|
|
public void setDeltaMovement(double x, double y, double z) {
|
|
@@ -4055,7 +4099,9 @@ public abstract class Entity implements Nameable, EntityAccess, CommandSource {
|
|
}
|
|
// Paper end - fix MC-4
|
|
if (this.position.x != x || this.position.y != y || this.position.z != z) {
|
|
+ synchronized (this.posLock) { // Paper
|
|
this.position = new Vec3(x, y, z);
|
|
+ } // Paper
|
|
int i = Mth.floor(x);
|
|
int j = Mth.floor(y);
|
|
int k = Mth.floor(z);
|
|
diff --git a/src/main/java/org/spigotmc/WatchdogThread.java b/src/main/java/org/spigotmc/WatchdogThread.java
|
|
index e0a71bfc1498a517456b21747ab6ef3f1067a3f3..e9fa7faaa4451e36b3908cbcbbe0baf213abde96 100644
|
|
--- a/src/main/java/org/spigotmc/WatchdogThread.java
|
|
+++ b/src/main/java/org/spigotmc/WatchdogThread.java
|
|
@@ -22,6 +22,78 @@ public final class WatchdogThread extends io.papermc.paper.util.TickThread // Pa
|
|
private volatile long lastTick;
|
|
private volatile boolean stopping;
|
|
|
|
+ // Paper start - log detailed tick information
|
|
+ private void dumpEntity(net.minecraft.world.entity.Entity entity) {
|
|
+ Logger log = Bukkit.getServer().getLogger();
|
|
+ double posX, posY, posZ;
|
|
+ net.minecraft.world.phys.Vec3 mot;
|
|
+ double moveStartX, moveStartY, moveStartZ;
|
|
+ net.minecraft.world.phys.Vec3 moveVec;
|
|
+ synchronized (entity.posLock) {
|
|
+ posX = entity.getX();
|
|
+ posY = entity.getY();
|
|
+ posZ = entity.getZ();
|
|
+ mot = entity.getDeltaMovement();
|
|
+ moveStartX = entity.getMoveStartX();
|
|
+ moveStartY = entity.getMoveStartY();
|
|
+ moveStartZ = entity.getMoveStartZ();
|
|
+ moveVec = entity.getMoveVector();
|
|
+ }
|
|
+
|
|
+ String entityType = net.minecraft.world.entity.EntityType.getKey(entity.getType()).toString();
|
|
+ java.util.UUID entityUUID = entity.getUUID();
|
|
+ net.minecraft.world.level.Level world = entity.level;
|
|
+
|
|
+ log.log(Level.SEVERE, "Ticking entity: " + entityType + ", entity class: " + entity.getClass().getName());
|
|
+ log.log(Level.SEVERE, "Entity status: removed: " + entity.isRemoved() + ", valid: " + entity.valid + ", alive: " + entity.isAlive() + ", is passenger: " + entity.isPassenger());
|
|
+ log.log(Level.SEVERE, "Entity UUID: " + entityUUID);
|
|
+ log.log(Level.SEVERE, "Position: world: '" + (world == null ? "unknown world?" : world.getWorld().getName()) + "' at location (" + posX + ", " + posY + ", " + posZ + ")");
|
|
+ log.log(Level.SEVERE, "Velocity: " + (mot == null ? "unknown velocity" : mot.toString()) + " (in blocks per tick)");
|
|
+ log.log(Level.SEVERE, "Entity AABB: " + entity.getBoundingBox());
|
|
+ if (moveVec != null) {
|
|
+ log.log(Level.SEVERE, "Move call information: ");
|
|
+ log.log(Level.SEVERE, "Start position: (" + moveStartX + ", " + moveStartY + ", " + moveStartZ + ")");
|
|
+ log.log(Level.SEVERE, "Move vector: " + moveVec.toString());
|
|
+ }
|
|
+ }
|
|
+
|
|
+ private void dumpTickingInfo() {
|
|
+ Logger log = Bukkit.getServer().getLogger();
|
|
+
|
|
+ // ticking entities
|
|
+ for (net.minecraft.world.entity.Entity entity : net.minecraft.server.level.ServerLevel.getCurrentlyTickingEntities()) {
|
|
+ this.dumpEntity(entity);
|
|
+ net.minecraft.world.entity.Entity vehicle = entity.getVehicle();
|
|
+ if (vehicle != null) {
|
|
+ log.log(Level.SEVERE, "Detailing vehicle for above entity:");
|
|
+ this.dumpEntity(vehicle);
|
|
+ }
|
|
+ }
|
|
+
|
|
+ // packet processors
|
|
+ for (net.minecraft.network.PacketListener packetListener : net.minecraft.network.protocol.PacketUtils.getCurrentPacketProcessors()) {
|
|
+ if (packetListener instanceof net.minecraft.server.network.ServerGamePacketListenerImpl) {
|
|
+ net.minecraft.server.level.ServerPlayer player = ((net.minecraft.server.network.ServerGamePacketListenerImpl)packetListener).player;
|
|
+ long totalPackets = net.minecraft.network.protocol.PacketUtils.getTotalProcessedPackets();
|
|
+ if (player == null) {
|
|
+ log.log(Level.SEVERE, "Handling packet for player connection or ticking player connection (null player): " + packetListener);
|
|
+ log.log(Level.SEVERE, "Total packets processed on the main thread for all players: " + totalPackets);
|
|
+ } else {
|
|
+ this.dumpEntity(player);
|
|
+ net.minecraft.world.entity.Entity vehicle = player.getVehicle();
|
|
+ if (vehicle != null) {
|
|
+ log.log(Level.SEVERE, "Detailing vehicle for above entity:");
|
|
+ this.dumpEntity(vehicle);
|
|
+ }
|
|
+ log.log(Level.SEVERE, "Total packets processed on the main thread for all players: " + totalPackets);
|
|
+ }
|
|
+ } else {
|
|
+ log.log(Level.SEVERE, "Handling packet for connection: " + packetListener);
|
|
+ }
|
|
+ }
|
|
+ }
|
|
+ // Paper end - log detailed tick information
|
|
+
|
|
private WatchdogThread(long timeoutTime, boolean restart)
|
|
{
|
|
super( "Paper Watchdog Thread" );
|
|
@@ -120,6 +192,7 @@ public final class WatchdogThread extends io.papermc.paper.util.TickThread // Pa
|
|
log.log( Level.SEVERE, "------------------------------" );
|
|
log.log( Level.SEVERE, "Server thread dump (Look for plugins here before reporting to Paper!):" ); // Paper
|
|
io.papermc.paper.chunk.system.scheduling.ChunkTaskScheduler.dumpAllChunkLoadInfo(isLongTimeout); // Paper // Paper - rewrite chunk system
|
|
+ this.dumpTickingInfo(); // Paper - log detailed tick information
|
|
WatchdogThread.dumpThread( ManagementFactory.getThreadMXBean().getThreadInfo( MinecraftServer.getServer().serverThread.getId(), Integer.MAX_VALUE ), log );
|
|
log.log( Level.SEVERE, "------------------------------" );
|
|
//
|