diff --git a/src/com/hypixel/hytale/server/core/entity/InteractionManager.java b/src/com/hypixel/hytale/server/core/entity/InteractionManager.java index 696c6c0f..7339e6dc 100644 --- a/src/com/hypixel/hytale/server/core/entity/InteractionManager.java +++ b/src/com/hypixel/hytale/server/core/entity/InteractionManager.java @@ -10,7 +10,6 @@ import com.hypixel.hytale.function.function.TriFunction; import com.hypixel.hytale.logger.HytaleLogger; import com.hypixel.hytale.math.util.ChunkUtil; import com.hypixel.hytale.math.vector.Vector4d; -import com.hypixel.hytale.metrics.metric.HistoricMetric; import com.hypixel.hytale.protocol.BlockPosition; import com.hypixel.hytale.protocol.ForkedChainId; import com.hypixel.hytale.protocol.GameMode; @@ -44,11 +43,6 @@ import com.hypixel.hytale.server.core.universe.world.World; import com.hypixel.hytale.server.core.universe.world.chunk.WorldChunk; import com.hypixel.hytale.server.core.universe.world.storage.EntityStore; import com.hypixel.hytale.server.core.util.UUIDUtil; -import io.sentry.Sentry; -import io.sentry.SentryEvent; -import io.sentry.SentryLevel; -import io.sentry.protocol.Message; -import io.sentry.protocol.SentryId; import it.unimi.dsi.fastutil.ints.Int2ObjectMap; import it.unimi.dsi.fastutil.ints.Int2ObjectMaps; import it.unimi.dsi.fastutil.ints.Int2ObjectOpenHashMap; @@ -59,7 +53,6 @@ import javax.annotation.Nonnull; import javax.annotation.Nullable; import java.util.Arrays; import java.util.Deque; -import java.util.HashMap; import java.util.Iterator; import java.util.List; import java.util.Map; @@ -198,7 +191,7 @@ public class InteractionManager implements Component { int highestChainId = -1; boolean changed = false; - label99: + label114: while (it.hasNext()) { SyncInteractionChain packet = it.next(); if (packet.desync) { @@ -234,7 +227,7 @@ public class InteractionManager implements Component { it.remove(); this.packetQueueTime = 0L; } - continue label99; + continue label114; } chain = subChain; @@ -242,50 +235,51 @@ public class InteractionManager implements Component { } highestChainId = Math.max(highestChainId, packet.chainId); - if (chain == null && !finished) { - if (this.syncStart(ref, packet)) { + boolean isProxy = packet.data != null && !UUIDUtil.isEmptyOrNull(packet.data.proxyId); + if ((chain != null || finished) && !isProxy) { + if (chain != null) { + this.sync(ref, chain, packet); changed = true; it.remove(); this.packetQueueTime = 0L; - } else { - if (!this.waitingForClient(ref)) { - long queuedTime; - if (this.packetQueueTime == 0L) { - this.packetQueueTime = this.currentTime; - queuedTime = 0L; - } else { - queuedTime = this.currentTime - this.packetQueueTime; - } - - HytaleLogger.Api context = LOGGER.at(Level.FINE); - if (context.isEnabled()) { - context.log("Queued chain %d for %s", packet.chainId, FormatUtil.nanosToString(queuedTime)); - } - - if (queuedTime > TimeUnit.MILLISECONDS.toNanos(this.getOperationTimeoutThreshold())) { - this.sendCancelPacket(packet.chainId, packet.forkedId); - it.remove(); - context = LOGGER.at(Level.FINE); - if (context.isEnabled()) { - context.log("Discarding packet due to queuing for too long: %s", packet); - } - } - } - - if (!desynced) { - finished = true; - } + } else if (desynced) { + this.sendCancelPacket(packet.chainId, packet.forkedId); + it.remove(); + HytaleLogger.Api ctx = LOGGER.at(Level.FINE); + ctx.log("Discarding packet due to desync: %s", packet); } - } else if (chain != null) { - this.sync(ref, chain, packet); + } else if (this.syncStart(ref, packet)) { changed = true; it.remove(); this.packetQueueTime = 0L; - } else if (desynced) { - this.sendCancelPacket(packet.chainId, packet.forkedId); - it.remove(); - HytaleLogger.Api ctx = LOGGER.at(Level.FINE); - ctx.log("Discarding packet due to desync: %s", packet); + } else { + if (!this.waitingForClient(ref)) { + long queuedTime; + if (this.packetQueueTime == 0L) { + this.packetQueueTime = this.currentTime; + queuedTime = 0L; + } else { + queuedTime = this.currentTime - this.packetQueueTime; + } + + HytaleLogger.Api context = LOGGER.at(Level.FINE); + if (context.isEnabled()) { + context.log("Queued chain %d for %s", packet.chainId, FormatUtil.nanosToString(queuedTime)); + } + + if (queuedTime > TimeUnit.MILLISECONDS.toNanos(this.getOperationTimeoutThreshold())) { + this.sendCancelPacket(packet.chainId, packet.forkedId); + it.remove(); + context = LOGGER.at(Level.FINE); + if (context.isEnabled()) { + context.log("Discarding packet due to queuing for too long: %s", packet); + } + } + } + + if (!desynced && !isProxy) { + finished = true; + } } } @@ -378,7 +372,7 @@ public class InteractionManager implements Component { long threshold = this.getOperationTimeoutThreshold(); TimeResource timeResource = this.commandBuffer.getResource(TimeResource.getResourceType()); if (timeResource.getTimeDilationModifier() == 1.0F && waitMillis > threshold) { - this.sendCancelPacket(chain); + this.cancelChains(chain); return chain.getForkedChains().isEmpty(); } } @@ -656,41 +650,10 @@ public class InteractionManager implements Component { long threshold = this.getOperationTimeoutThreshold(); if (tickTimeDilation == 1.0F && waitMillis > threshold) { - SentryEvent event = new SentryEvent(); - event.setLevel(SentryLevel.ERROR); - Message message = new Message(); - message.setMessage("Client failed to send client data, ending early to prevent desync"); - HashMap unknown = new HashMap<>(); - unknown.put("Threshold", threshold); - unknown.put("Wait Millis", waitMillis); - unknown.put("Current Root", chain.getRootInteraction() != null ? chain.getRootInteraction().getId() : ""); - Operation innerOp = operation.getInnerOperation(); - unknown.put("Current Op", innerOp.getClass().getName()); - if (innerOp instanceof Interaction interaction) { - unknown.put("Current Interaction", interaction.getId()); - } - - unknown.put("Current Index", chain.getOperationIndex()); - unknown.put("Current Op Counter", chain.getOperationCounter()); - HistoricMetric metric = ref.getStore().getExternalData().getWorld().getBufferedTickLengthMetricSet(); - long[] periods = metric.getPeriodsNanos(); - - for (int i = 0; i < periods.length; i++) { - String length = FormatUtil.timeUnitToString(periods[i], TimeUnit.NANOSECONDS, true); - double average = metric.getAverage(i); - long min = metric.calculateMin(i); - long max = metric.calculateMax(i); - String value = FormatUtil.simpleTimeUnitFormat(min, average, max, TimeUnit.NANOSECONDS, TimeUnit.MILLISECONDS, 3); - unknown.put(String.format("World Perf %s", length), value); - } - - event.setExtras(unknown); - event.setMessage(message); - SentryId eventId = Sentry.captureEvent(event); - LOGGER.atWarning().log("Client failed to send client data, ending early to prevent desync. %s", eventId); + LOGGER.atWarning().log("Client failed to send client data, ending early to prevent desync."); chain.setServerState(InteractionState.Failed); chain.setClientState(InteractionState.Failed); - this.sendCancelPacket(chain); + this.cancelChains(chain); return null; } else { if (entry.consumeSendInitial() || wasWrong) { @@ -783,6 +746,8 @@ public class InteractionManager implements Component { if (ctx.isEnabled()) { ctx.log("Got syncStart for %d-%s but packet wasn't the first.", index, packet.forkedId); } + + this.sendCancelPacket(index, packet.forkedId); } return true; @@ -792,6 +757,7 @@ public class InteractionManager implements Component { ctx.log("Can't start a forked chain from the client: %d %s", index, packet.forkedId); } + this.sendCancelPacket(index, packet.forkedId); return true; } else { InteractionType type = packet.interactionType; @@ -1369,7 +1335,7 @@ public class InteractionManager implements Component { this.sendCancelPacket(chain.getChainId(), chain.getForkedChainId()); } - public void sendCancelPacket(int chainId, @Nonnull ForkedChainId forkedChainId) { + public void sendCancelPacket(int chainId, ForkedChainId forkedChainId) { if (this.playerRef != null) { this.playerRef.getPacketHandler().writeNoCache(new CancelInteractionChain(chainId, forkedChainId)); } diff --git a/src/com/hypixel/hytale/server/core/io/PacketHandler.java b/src/com/hypixel/hytale/server/core/io/PacketHandler.java index 888141a8..8eb07aca 100644 --- a/src/com/hypixel/hytale/server/core/io/PacketHandler.java +++ b/src/com/hypixel/hytale/server/core/io/PacketHandler.java @@ -411,10 +411,12 @@ public abstract class PacketHandler implements IPacketReceiver { Attribute loginStartAttribute = channel.attr(LOGIN_START_ATTRIBUTE_KEY); long now = System.nanoTime(); Long before = loginStartAttribute.getAndSet(now); + NettyUtil.TimeoutContext context = channel.attr(NettyUtil.TimeoutContext.KEY).get(); + String identifier = context != null ? context.playerIdentifier() : NettyUtil.formatRemoteAddress(channel); if (before == null) { - LOGIN_TIMING_LOGGER.at(level).log(message); + LOGIN_TIMING_LOGGER.at(level).log("[%s] %s", identifier, message); } else { - LOGIN_TIMING_LOGGER.at(level).log("%s took %s", message, LazyArgs.lazy(() -> FormatUtil.nanosToString(now - before))); + LOGIN_TIMING_LOGGER.at(level).log("[%s] %s took %s", identifier, message, LazyArgs.lazy(() -> FormatUtil.nanosToString(now - before))); } } diff --git a/src/com/hypixel/hytale/server/core/universe/Universe.java b/src/com/hypixel/hytale/server/core/universe/Universe.java index 3dffb17f..4e74c2b6 100644 --- a/src/com/hypixel/hytale/server/core/universe/Universe.java +++ b/src/com/hypixel/hytale/server/core/universe/Universe.java @@ -699,42 +699,60 @@ public class Universe extends JavaPlugin implements IMessageReceiver, MetricProv .getEventBus() .dispatchFor(PlayerConnectEvent.class) .dispatch(new PlayerConnectEvent((Holder) holder, playerRefComponent, lastWorld != null ? lastWorld : this.getDefaultWorld())); - World world = event.getWorld() != null ? event.getWorld() : this.getDefaultWorld(); - if (world == null) { + if (!channel.isActive()) { this.players.remove(uuid, playerRefComponent); - playerConnection.disconnect("No world available to join"); - this.getLogger().at(Level.SEVERE).log("Player '%s' (%s) could not join - no default world configured", username, uuid); + this.getLogger().at(Level.INFO).log("Player '%s' (%s) disconnected during PlayerConnectEvent, cleaned up", username, uuid); return CompletableFuture.completedFuture(null); } else { - if (lastWorldName != null && lastWorld == null) { - playerComponent.sendMessage( - Message.translation("server.universe.failedToFindWorld").param("lastWorldName", lastWorldName).param("name", world.getName()) - ); - } - - PacketHandler.logConnectionTimings(channel, "Processed Referral", Level.FINEST); - playerRefComponent.getPacketHandler().write(new ServerTags(AssetRegistry.getClientTags())); - return world.addPlayer(playerRefComponent, null, false, false).thenApply(p -> { - PacketHandler.logConnectionTimings(channel, "Add to World", Level.FINEST); - if (!channel.isActive()) { - if (p != null) { - playerComponent.remove(); - } - - this.players.remove(uuid, playerRefComponent); - this.getLogger().at(Level.WARNING).log("Player '%s' (%s) disconnected during world join, cleaned up from universe", username, uuid); - return null; - } else if (playerComponent.wasRemoved()) { - this.players.remove(uuid, playerRefComponent); - return null; - } else { - return (PlayerRef) p; - } - }).exceptionally(throwable -> { + World world = event.getWorld() != null ? event.getWorld() : this.getDefaultWorld(); + if (world == null) { this.players.remove(uuid, playerRefComponent); - playerComponent.remove(); - throw new RuntimeException("Exception when adding player to universe:", throwable); - }); + playerConnection.disconnect("No world available to join"); + this.getLogger().at(Level.SEVERE).log("Player '%s' (%s) could not join - no default world configured", username, uuid); + return CompletableFuture.completedFuture(null); + } else { + if (lastWorldName != null && lastWorld == null) { + playerComponent.sendMessage( + Message.translation("server.universe.failedToFindWorld").param("lastWorldName", lastWorldName).param("name", world.getName()) + ); + } + + PacketHandler.logConnectionTimings(channel, "Processed Referral", Level.FINEST); + playerRefComponent.getPacketHandler().write(new ServerTags(AssetRegistry.getClientTags())); + CompletableFuture addPlayerFuture = world.addPlayer(playerRefComponent, null, false, false); + if (addPlayerFuture == null) { + this.players.remove(uuid, playerRefComponent); + this.getLogger().at(Level.INFO).log("Player '%s' (%s) disconnected before world addition, cleaned up", username, uuid); + return CompletableFuture.completedFuture(null); + } else { + return addPlayerFuture.thenApply( + p -> { + PacketHandler.logConnectionTimings(channel, "Add to World", Level.FINEST); + if (!channel.isActive()) { + if (p != null) { + playerComponent.remove(); + } + + this.players.remove(uuid, playerRefComponent); + this.getLogger() + .at(Level.WARNING) + .log("Player '%s' (%s) disconnected during world join, cleaned up from universe", username, uuid); + return null; + } else if (playerComponent.wasRemoved()) { + this.players.remove(uuid, playerRefComponent); + return null; + } else { + return (PlayerRef) p; + } + } + ) + .exceptionally(throwable -> { + this.players.remove(uuid, playerRefComponent); + playerComponent.remove(); + throw new RuntimeException("Exception when adding player to universe:", throwable); + }); + } + } } } } diff --git a/src/com/hypixel/hytale/server/core/universe/world/storage/provider/IndexedStorageChunkStorageProvider.java b/src/com/hypixel/hytale/server/core/universe/world/storage/provider/IndexedStorageChunkStorageProvider.java index 45feb45d..6693e761 100644 --- a/src/com/hypixel/hytale/server/core/universe/world/storage/provider/IndexedStorageChunkStorageProvider.java +++ b/src/com/hypixel/hytale/server/core/universe/world/storage/provider/IndexedStorageChunkStorageProvider.java @@ -68,7 +68,7 @@ public class IndexedStorageChunkStorageProvider implements IChunkStorageProvider ) .add() .build(); - private boolean flushOnWrite = true; + private boolean flushOnWrite = false; public IndexedStorageChunkStorageProvider() { }