diff --git a/changelogs/4.18.md b/changelogs/4.18.md index 890f00d6d..940a855bd 100644 --- a/changelogs/4.18.md +++ b/changelogs/4.18.md @@ -109,3 +109,15 @@ Released 5th April 2023. - Fixed not being able to drop items directly from the creative inventory on mobile. - Fixed `DataPacketReceiveEvent` not being called for packets sent by `EntityEventBroadcaster`. - `CreativeInventory::getItem()` and `CreativeInventory::getAll()` now return cloned itemstacks, to prevent accidental modification of the creative inventory. + +# 4.18.4 +Released 10th April 2023. + +## Fixes +- Fixed movement becoming broken when the player moves at high speed (e.g. due to high levels of the Speed effect). +- Updated dependencies to get fixes in `pocketmine/nbt` and `pocketmine/bedrock-protocol`. + +## Internals +### Network +- Game packets are now rate-limited in a similar manner to packet batches. This helps to more effectively mitigate certain types of DoS attacks. +- Added a new class `PacketRateLimiter`, implementing functionality previously baked directly into `NetworkSession` in a more generic way to allow reuse. diff --git a/composer.lock b/composer.lock index 69871ae94..2a14a4aa2 100644 --- a/composer.lock +++ b/composer.lock @@ -199,16 +199,16 @@ }, { "name": "netresearch/jsonmapper", - "version": "v4.1.0", + "version": "v4.2.0", "source": { "type": "git", "url": "https://github.com/cweiske/jsonmapper.git", - "reference": "cfa81ea1d35294d64adb9c68aa4cb9e92400e53f" + "reference": "f60565f8c0566a31acf06884cdaa591867ecc956" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/cweiske/jsonmapper/zipball/cfa81ea1d35294d64adb9c68aa4cb9e92400e53f", - "reference": "cfa81ea1d35294d64adb9c68aa4cb9e92400e53f", + "url": "https://api.github.com/repos/cweiske/jsonmapper/zipball/f60565f8c0566a31acf06884cdaa591867ecc956", + "reference": "f60565f8c0566a31acf06884cdaa591867ecc956", "shasum": "" }, "require": { @@ -244,9 +244,9 @@ "support": { "email": "cweiske@cweiske.de", "issues": "https://github.com/cweiske/jsonmapper/issues", - "source": "https://github.com/cweiske/jsonmapper/tree/v4.1.0" + "source": "https://github.com/cweiske/jsonmapper/tree/v4.2.0" }, - "time": "2022-12-08T20:46:14+00:00" + "time": "2023-04-09T17:37:40+00:00" }, { "name": "pocketmine/bedrock-block-upgrade-schema", @@ -328,16 +328,16 @@ }, { "name": "pocketmine/bedrock-protocol", - "version": "20.1.1+bedrock-1.19.70", + "version": "20.1.2+bedrock-1.19.70", "source": { "type": "git", "url": "https://github.com/pmmp/BedrockProtocol.git", - "reference": "455dbad93d29b4489b60910a41e38b8007b26563" + "reference": "2787c531039b3d92fa3ec92f28b95158dc24b915" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/pmmp/BedrockProtocol/zipball/455dbad93d29b4489b60910a41e38b8007b26563", - "reference": "455dbad93d29b4489b60910a41e38b8007b26563", + "url": "https://api.github.com/repos/pmmp/BedrockProtocol/zipball/2787c531039b3d92fa3ec92f28b95158dc24b915", + "reference": "2787c531039b3d92fa3ec92f28b95158dc24b915", "shasum": "" }, "require": { @@ -369,9 +369,9 @@ "description": "An implementation of the Minecraft: Bedrock Edition protocol in PHP", "support": { "issues": "https://github.com/pmmp/BedrockProtocol/issues", - "source": "https://github.com/pmmp/BedrockProtocol/tree/20.1.1+bedrock-1.19.70" + "source": "https://github.com/pmmp/BedrockProtocol/tree/20.1.2+bedrock-1.19.70" }, - "time": "2023-03-29T22:38:17+00:00" + "time": "2023-04-10T11:40:32+00:00" }, { "name": "pocketmine/binaryutils", @@ -512,23 +512,23 @@ }, { "name": "pocketmine/color", - "version": "0.3.0", + "version": "0.3.1", "source": { "type": "git", "url": "https://github.com/pmmp/Color.git", - "reference": "8cb346d0a21ad3287cc8d7175e4b643416607249" + "reference": "a0421f1e9e0b0c619300fb92d593283378f6a5e1" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/pmmp/Color/zipball/8cb346d0a21ad3287cc8d7175e4b643416607249", - "reference": "8cb346d0a21ad3287cc8d7175e4b643416607249", + "url": "https://api.github.com/repos/pmmp/Color/zipball/a0421f1e9e0b0c619300fb92d593283378f6a5e1", + "reference": "a0421f1e9e0b0c619300fb92d593283378f6a5e1", "shasum": "" }, "require": { "php": "^8.0" }, "require-dev": { - "phpstan/phpstan": "1.9.4", + "phpstan/phpstan": "1.10.3", "phpstan/phpstan-strict-rules": "^1.2.0" }, "type": "library", @@ -544,9 +544,9 @@ "description": "Color handling library used by PocketMine-MP and related projects", "support": { "issues": "https://github.com/pmmp/Color/issues", - "source": "https://github.com/pmmp/Color/tree/0.3.0" + "source": "https://github.com/pmmp/Color/tree/0.3.1" }, - "time": "2022-12-18T19:49:21+00:00" + "time": "2023-04-10T11:38:05+00:00" }, { "name": "pocketmine/errorhandler", @@ -738,16 +738,16 @@ }, { "name": "pocketmine/nbt", - "version": "0.3.3", + "version": "0.3.4", "source": { "type": "git", "url": "https://github.com/pmmp/NBT.git", - "reference": "f4321be50df1a18b9f4e94d428a2e68a6e2ac2b4" + "reference": "62c02464c6708b2467c1e1a2af01af09d5114eda" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/pmmp/NBT/zipball/f4321be50df1a18b9f4e94d428a2e68a6e2ac2b4", - "reference": "f4321be50df1a18b9f4e94d428a2e68a6e2ac2b4", + "url": "https://api.github.com/repos/pmmp/NBT/zipball/62c02464c6708b2467c1e1a2af01af09d5114eda", + "reference": "62c02464c6708b2467c1e1a2af01af09d5114eda", "shasum": "" }, "require": { @@ -757,7 +757,7 @@ }, "require-dev": { "phpstan/extension-installer": "^1.0", - "phpstan/phpstan": "1.7.7", + "phpstan/phpstan": "1.10.3", "phpstan/phpstan-strict-rules": "^1.0", "phpunit/phpunit": "^9.5" }, @@ -774,9 +774,9 @@ "description": "PHP library for working with Named Binary Tags", "support": { "issues": "https://github.com/pmmp/NBT/issues", - "source": "https://github.com/pmmp/NBT/tree/0.3.3" + "source": "https://github.com/pmmp/NBT/tree/0.3.4" }, - "time": "2022-07-06T14:13:26+00:00" + "time": "2023-04-10T11:31:20+00:00" }, { "name": "pocketmine/raklib", diff --git a/src/command/defaults/TimingsCommand.php b/src/command/defaults/TimingsCommand.php index 00f0a057f..86419fc12 100644 --- a/src/command/defaults/TimingsCommand.php +++ b/src/command/defaults/TimingsCommand.php @@ -163,6 +163,7 @@ class TimingsCommand extends VanillaCommand{ Command::broadcastCommandMessage($sender, KnownTranslationFactory::pocketmine_command_timings_timingsRead( "https://" . $host . "/?id=" . $response["id"])); }else{ + $sender->getServer()->getLogger()->debug("Invalid response from timings server: " . $result->getBody()); Command::broadcastCommandMessage($sender, KnownTranslationFactory::pocketmine_command_timings_pasteError()); } } diff --git a/src/entity/object/ExperienceOrb.php b/src/entity/object/ExperienceOrb.php index ce2a766f0..0d3af7e6c 100644 --- a/src/entity/object/ExperienceOrb.php +++ b/src/entity/object/ExperienceOrb.php @@ -32,6 +32,7 @@ use pocketmine\network\mcpe\protocol\types\entity\EntityIds; use pocketmine\network\mcpe\protocol\types\entity\EntityMetadataCollection; use pocketmine\network\mcpe\protocol\types\entity\EntityMetadataProperties; use pocketmine\player\Player; +use function max; use function sqrt; class ExperienceOrb extends Entity{ @@ -48,6 +49,10 @@ class ExperienceOrb extends Entity{ /** Split sizes used for dropping experience orbs. */ public const ORB_SPLIT_SIZES = [2477, 1237, 617, 307, 149, 73, 37, 17, 7, 3, 1]; //This is indexed biggest to smallest so that we can return as soon as we found the biggest value. + public const DEFAULT_DESPAWN_DELAY = 6000; + public const NEVER_DESPAWN = -1; + public const MAX_DESPAWN_DELAY = 32767 + self::DEFAULT_DESPAWN_DELAY; //max value storable by mojang NBT :( + /** * Returns the largest size of normal XP orb that will be spawned for the specified amount of XP. Used to split XP * up into multiple orbs when an amount of XP is dropped. @@ -79,6 +84,7 @@ class ExperienceOrb extends Entity{ return $result; } + /** @deprecated */ protected int $age = 0; /** Ticker used for determining interval in which to look for new target players. */ @@ -89,6 +95,8 @@ class ExperienceOrb extends Entity{ protected int $xpValue; + private int $despawnDelay = self::DEFAULT_DESPAWN_DELAY; + public function __construct(Location $location, int $xpValue, ?CompoundTag $nbt = null){ $this->xpValue = $xpValue; parent::__construct($location, $nbt); @@ -104,12 +112,22 @@ class ExperienceOrb extends Entity{ parent::initEntity($nbt); $this->age = $nbt->getShort(self::TAG_AGE, 0); + if($this->age === -32768){ + $this->despawnDelay = self::NEVER_DESPAWN; + }else{ + $this->despawnDelay = max(0, self::DEFAULT_DESPAWN_DELAY - $this->age); + } } public function saveNBT() : CompoundTag{ $nbt = parent::saveNBT(); - $nbt->setShort(self::TAG_AGE, $this->age); + if($this->despawnDelay === self::NEVER_DESPAWN){ + $age = -32768; + }else{ + $age = self::DEFAULT_DESPAWN_DELAY - $this->despawnDelay; + } + $nbt->setShort(self::TAG_AGE, $age); $nbt->setShort(self::TAG_VALUE_PC, $this->getXpValue()); $nbt->setInt(self::TAG_VALUE_PE, $this->getXpValue()); @@ -117,6 +135,15 @@ class ExperienceOrb extends Entity{ return $nbt; } + public function getDespawnDelay() : int{ return $this->despawnDelay; } + + public function setDespawnDelay(int $despawnDelay) : void{ + if(($despawnDelay < 0 || $despawnDelay > self::MAX_DESPAWN_DELAY) && $despawnDelay !== self::NEVER_DESPAWN){ + throw new \InvalidArgumentException("Despawn ticker must be in range 0 ... " . self::MAX_DESPAWN_DELAY . " or " . self::NEVER_DESPAWN . ", got $despawnDelay"); + } + $this->despawnDelay = $despawnDelay; + } + public function getXpValue() : int{ return $this->xpValue; } @@ -154,7 +181,8 @@ class ExperienceOrb extends Entity{ $hasUpdate = parent::entityBaseTick($tickDiff); $this->age += $tickDiff; - if($this->age > 6000){ + $this->despawnDelay -= $tickDiff; + if($this->despawnDelay <= 0){ $this->flagForDespawn(); return true; } diff --git a/src/event/Event.php b/src/event/Event.php index 8e1276c41..5488285b2 100644 --- a/src/event/Event.php +++ b/src/event/Event.php @@ -58,15 +58,8 @@ abstract class Event{ ++self::$eventCallDepth; try{ - foreach(EventPriority::ALL as $priority){ - $currentList = $handlerList; - while($currentList !== null){ - foreach($currentList->getListenersByPriority($priority) as $registration){ - $registration->callEvent($this); - } - - $currentList = $currentList->getParent(); - } + foreach($handlerList->getListenerList() as $registration){ + $registration->callEvent($this); } }finally{ --self::$eventCallDepth; diff --git a/src/event/EventPriority.php b/src/event/EventPriority.php index cdeb3136a..99c71faff 100644 --- a/src/event/EventPriority.php +++ b/src/event/EventPriority.php @@ -32,6 +32,8 @@ use function mb_strtoupper; * LOWEST -> LOW -> NORMAL -> HIGH -> HIGHEST -> MONITOR * * MONITOR events should not change the event outcome or contents + * + * WARNING: If these values are changed, handler sorting in HandlerList::getListenerList() may need to be updated. */ final class EventPriority{ diff --git a/src/event/HandlerList.php b/src/event/HandlerList.php index 8a3fb8d92..6b1a39d94 100644 --- a/src/event/HandlerList.php +++ b/src/event/HandlerList.php @@ -24,13 +24,20 @@ declare(strict_types=1); namespace pocketmine\event; use pocketmine\plugin\Plugin; -use function array_fill_keys; +use function array_merge; +use function krsort; use function spl_object_id; +use const SORT_NUMERIC; class HandlerList{ /** @var RegisteredListener[][] */ private array $handlerSlots = []; + private RegisteredListenerCache $handlerCache; + + /** @var RegisteredListenerCache[] */ + private array $affectedHandlerCaches = []; + /** * @phpstan-template TEvent of Event * @phpstan-param class-string $class @@ -39,7 +46,10 @@ class HandlerList{ private string $class, private ?HandlerList $parentList ){ - $this->handlerSlots = array_fill_keys(EventPriority::ALL, []); + $this->handlerCache = new RegisteredListenerCache(); + for($list = $this; $list !== null; $list = $list->parentList){ + $list->affectedHandlerCaches[spl_object_id($this->handlerCache)] = $this->handlerCache; + } } /** @@ -50,6 +60,7 @@ class HandlerList{ throw new \InvalidArgumentException("This listener is already registered to priority {$listener->getPriority()} of event {$this->class}"); } $this->handlerSlots[$listener->getPriority()][spl_object_id($listener)] = $listener; + $this->invalidateAffectedCaches(); } /** @@ -59,6 +70,7 @@ class HandlerList{ foreach($listeners as $listener){ $this->register($listener); } + $this->invalidateAffectedCaches(); } public function unregister(RegisteredListener|Plugin|Listener $object) : void{ @@ -73,14 +85,14 @@ class HandlerList{ } } }else{ - if(isset($this->handlerSlots[$object->getPriority()][spl_object_id($object)])){ - unset($this->handlerSlots[$object->getPriority()][spl_object_id($object)]); - } + unset($this->handlerSlots[$object->getPriority()][spl_object_id($object)]); } + $this->invalidateAffectedCaches(); } public function clear() : void{ - $this->handlerSlots = array_fill_keys(EventPriority::ALL, []); + $this->handlerSlots = []; + $this->invalidateAffectedCaches(); } /** @@ -93,4 +105,40 @@ class HandlerList{ public function getParent() : ?HandlerList{ return $this->parentList; } + + /** + * Invalidates all known caches which might be affected by this list's contents. + */ + private function invalidateAffectedCaches() : void{ + foreach($this->affectedHandlerCaches as $cache){ + $cache->list = null; + } + } + + /** + * @return RegisteredListener[] + * @phpstan-return list + */ + public function getListenerList() : array{ + if($this->handlerCache->list !== null){ + return $this->handlerCache->list; + } + + $handlerLists = []; + for($currentList = $this; $currentList !== null; $currentList = $currentList->parentList){ + $handlerLists[] = $currentList; + } + + $listenersByPriority = []; + foreach($handlerLists as $currentList){ + foreach($currentList->handlerSlots as $priority => $listeners){ + $listenersByPriority[$priority] = array_merge($listenersByPriority[$priority] ?? [], $listeners); + } + } + + //TODO: why on earth do the priorities have higher values for lower priority? + krsort($listenersByPriority, SORT_NUMERIC); + + return $this->handlerCache->list = array_merge(...$listenersByPriority); + } } diff --git a/src/event/RegisteredListenerCache.php b/src/event/RegisteredListenerCache.php new file mode 100644 index 000000000..1b675c716 --- /dev/null +++ b/src/event/RegisteredListenerCache.php @@ -0,0 +1,35 @@ + + */ + public ?array $list = null; +} diff --git a/src/network/mcpe/NetworkSession.php b/src/network/mcpe/NetworkSession.php index e9cd5c724..160a06eaf 100644 --- a/src/network/mcpe/NetworkSession.php +++ b/src/network/mcpe/NetworkSession.php @@ -114,11 +114,8 @@ use function base64_encode; use function bin2hex; use function count; use function get_class; -use function hrtime; use function in_array; -use function intdiv; use function json_encode; -use function min; use function random_bytes; use function strcasecmp; use function strlen; @@ -129,19 +126,14 @@ use function ucfirst; use const JSON_THROW_ON_ERROR; class NetworkSession{ - private const INCOMING_PACKET_BATCH_PER_TICK = 2; //usually max 1 per tick, but transactions may arrive separately - private const INCOMING_PACKET_BATCH_MAX_BUDGET = 100 * self::INCOMING_PACKET_BATCH_PER_TICK; //enough to account for a 5-second lag spike + private const INCOMING_PACKET_BATCH_PER_TICK = 2; //usually max 1 per tick, but transactions arrive separately + private const INCOMING_PACKET_BATCH_BUFFER_TICKS = 100; //enough to account for a 5-second lag spike - /** - * At most this many more packets can be received. If this reaches zero, any additional packets received will cause - * the player to be kicked from the server. - * This number is increased every tick up to a maximum limit. - * - * @see self::INCOMING_PACKET_BATCH_PER_TICK - * @see self::INCOMING_PACKET_BATCH_MAX_BUDGET - */ - private int $incomingPacketBatchBudget = self::INCOMING_PACKET_BATCH_MAX_BUDGET; - private int $lastPacketBudgetUpdateTimeNs; + private const INCOMING_GAME_PACKETS_PER_TICK = 2; + private const INCOMING_GAME_PACKETS_BUFFER_TICKS = 100; + + private PacketRateLimiter $packetBatchLimiter; + private PacketRateLimiter $gamePacketLimiter; private \PrefixedLogger $logger; private ?Player $player = null; @@ -197,7 +189,8 @@ class NetworkSession{ $this->disposeHooks = new ObjectSet(); $this->connectTime = time(); - $this->lastPacketBudgetUpdateTimeNs = hrtime(true); + $this->packetBatchLimiter = new PacketRateLimiter("Packet Batches", self::INCOMING_PACKET_BATCH_PER_TICK, self::INCOMING_PACKET_BATCH_BUFFER_TICKS); + $this->gamePacketLimiter = new PacketRateLimiter("Game Packets", self::INCOMING_GAME_PACKETS_PER_TICK, self::INCOMING_GAME_PACKETS_BUFFER_TICKS); $this->setHandler(new SessionStartPacketHandler( $this, @@ -341,13 +334,7 @@ class NetworkSession{ Timings::$playerNetworkReceive->startTiming(); try{ - if($this->incomingPacketBatchBudget <= 0){ - $this->updatePacketBudget(); - if($this->incomingPacketBatchBudget <= 0){ - throw new PacketHandlingException("Receiving packets too fast"); - } - } - $this->incomingPacketBatchBudget--; + $this->packetBatchLimiter->decrement(); if($this->cipher !== null){ Timings::$playerNetworkReceiveDecrypt->startTiming(); @@ -379,6 +366,7 @@ class NetworkSession{ $stream = new BinaryStream($decompressed); $count = 0; foreach(PacketBatch::decodeRaw($stream) as $buffer){ + $this->gamePacketLimiter->decrement(); if(++$count > 100){ throw new PacketHandlingException("Too many packets in batch"); } @@ -1150,23 +1138,6 @@ class NetworkSession{ $this->sendDataPacket(ToastRequestPacket::create($title, $body)); } - private function updatePacketBudget() : void{ - $nowNs = hrtime(true); - $timeSinceLastUpdateNs = $nowNs - $this->lastPacketBudgetUpdateTimeNs; - if($timeSinceLastUpdateNs > 50_000_000){ - $ticksSinceLastUpdate = intdiv($timeSinceLastUpdateNs, 50_000_000); - /* - * If the server takes an abnormally long time to process a tick, add the budget for time difference to - * compensate. This extra budget may be very large, but it will disappear the next time a normal update - * occurs. This ensures that backlogs during a large lag spike don't cause everyone to get kicked. - * As long as all the backlogged packets are processed before the next tick, everything should be OK for - * clients behaving normally. - */ - $this->incomingPacketBatchBudget = min($this->incomingPacketBatchBudget, self::INCOMING_PACKET_BATCH_MAX_BUDGET) + (self::INCOMING_PACKET_BATCH_PER_TICK * 2 * $ticksSinceLastUpdate); - $this->lastPacketBudgetUpdateTimeNs = $nowNs; - } - } - public function tick() : void{ if(!$this->isConnected()){ $this->dispose(); diff --git a/src/network/mcpe/PacketRateLimiter.php b/src/network/mcpe/PacketRateLimiter.php new file mode 100644 index 000000000..3f0fbf768 --- /dev/null +++ b/src/network/mcpe/PacketRateLimiter.php @@ -0,0 +1,81 @@ +maxBudget = $this->averagePerTick * $maxBufferTicks; + $this->budget = $this->maxBudget; + $this->lastUpdateTimeNs = hrtime(true); + } + + /** + * @throws PacketHandlingException if the rate limit has been exceeded + */ + public function decrement(int $amount = 1) : void{ + if($this->budget <= 0){ + $this->update(); + if($this->budget <= 0){ + throw new PacketHandlingException("Exceeded rate limit for \"$this->name\""); + } + } + $this->budget -= $amount; + } + + public function update() : void{ + $nowNs = hrtime(true); + $timeSinceLastUpdateNs = $nowNs - $this->lastUpdateTimeNs; + if($timeSinceLastUpdateNs > $this->updateFrequencyNs){ + $ticksSinceLastUpdate = intdiv($timeSinceLastUpdateNs, $this->updateFrequencyNs); + /* + * If the server takes an abnormally long time to process a tick, add the budget for time difference to + * compensate. This extra budget may be very large, but it will disappear the next time a normal update + * occurs. This ensures that backlogs during a large lag spike don't cause everyone to get kicked. + * As long as all the backlogged packets are processed before the next tick, everything should be OK for + * clients behaving normally. + */ + $this->budget = min($this->budget, $this->maxBudget) + ($this->averagePerTick * 2 * $ticksSinceLastUpdate); + $this->lastUpdateTimeNs = $nowNs; + } + } +} diff --git a/src/network/mcpe/handler/InGamePacketHandler.php b/src/network/mcpe/handler/InGamePacketHandler.php index 7b8776b9f..95f693c9c 100644 --- a/src/network/mcpe/handler/InGamePacketHandler.php +++ b/src/network/mcpe/handler/InGamePacketHandler.php @@ -211,7 +211,7 @@ class InGamePacketHandler extends PacketHandler{ if($newPos->distanceSquared($curPos) > 1){ //Tolerate up to 1 block to avoid problems with client-sided physics when spawning in blocks $this->session->getLogger()->debug("Got outdated pre-teleport movement, received " . $newPos . ", expected " . $curPos); //Still getting movements from before teleport, ignore them - return false; + return true; } // Once we get a movement within a reasonable distance, treat it as a teleport ACK and remove position lock diff --git a/src/network/mcpe/handler/PreSpawnPacketHandler.php b/src/network/mcpe/handler/PreSpawnPacketHandler.php index 8c47f6583..e914a0a2e 100644 --- a/src/network/mcpe/handler/PreSpawnPacketHandler.php +++ b/src/network/mcpe/handler/PreSpawnPacketHandler.php @@ -44,6 +44,7 @@ use pocketmine\network\mcpe\protocol\types\PlayerMovementType; use pocketmine\network\mcpe\protocol\types\SpawnSettings; use pocketmine\player\Player; use pocketmine\Server; +use pocketmine\timings\Timings; use pocketmine\VersionInfo; use Ramsey\Uuid\Uuid; use function sprintf; @@ -60,89 +61,94 @@ class PreSpawnPacketHandler extends PacketHandler{ ){} public function setUp() : void{ - $location = $this->player->getLocation(); - $world = $location->getWorld(); + Timings::$playerNetworkSendPreSpawnGameData->startTiming(); + try{ + $location = $this->player->getLocation(); + $world = $location->getWorld(); - $this->session->getLogger()->debug("Preparing StartGamePacket"); - $levelSettings = new LevelSettings(); - $levelSettings->seed = -1; - $levelSettings->spawnSettings = new SpawnSettings(SpawnSettings::BIOME_TYPE_DEFAULT, "", DimensionIds::OVERWORLD); //TODO: implement this properly - $levelSettings->worldGamemode = TypeConverter::getInstance()->coreGameModeToProtocol($this->server->getGamemode()); - $levelSettings->difficulty = $world->getDifficulty(); - $levelSettings->spawnPosition = BlockPosition::fromVector3($world->getSpawnLocation()); - $levelSettings->hasAchievementsDisabled = true; - $levelSettings->time = $world->getTime(); - $levelSettings->eduEditionOffer = 0; - $levelSettings->rainLevel = 0; //TODO: implement these properly - $levelSettings->lightningLevel = 0; - $levelSettings->commandsEnabled = true; - $levelSettings->gameRules = [ - "naturalregeneration" => new BoolGameRule(false, false) //Hack for client side regeneration - ]; - $levelSettings->experiments = new Experiments([], false); + $this->session->getLogger()->debug("Preparing StartGamePacket"); + $levelSettings = new LevelSettings(); + $levelSettings->seed = -1; + $levelSettings->spawnSettings = new SpawnSettings(SpawnSettings::BIOME_TYPE_DEFAULT, "", DimensionIds::OVERWORLD); //TODO: implement this properly + $levelSettings->worldGamemode = TypeConverter::getInstance()->coreGameModeToProtocol($this->server->getGamemode()); + $levelSettings->difficulty = $world->getDifficulty(); + $levelSettings->spawnPosition = BlockPosition::fromVector3($world->getSpawnLocation()); + $levelSettings->hasAchievementsDisabled = true; + $levelSettings->time = $world->getTime(); + $levelSettings->eduEditionOffer = 0; + $levelSettings->rainLevel = 0; //TODO: implement these properly + $levelSettings->lightningLevel = 0; + $levelSettings->commandsEnabled = true; + $levelSettings->gameRules = [ + "naturalregeneration" => new BoolGameRule(false, false) //Hack for client side regeneration + ]; + $levelSettings->experiments = new Experiments([], false); - $this->session->sendDataPacket(StartGamePacket::create( - $this->player->getId(), - $this->player->getId(), - TypeConverter::getInstance()->coreGameModeToProtocol($this->player->getGamemode()), - $this->player->getOffsetPosition($location), - $location->pitch, - $location->yaw, - new CacheableNbt(CompoundTag::create()), //TODO: we don't care about this right now - $levelSettings, - "", - $this->server->getMotd(), - "", - false, - new PlayerMovementSettings(PlayerMovementType::SERVER_AUTHORITATIVE_V1, 0, false), - 0, - 0, - "", - true, - sprintf("%s %s", VersionInfo::NAME, VersionInfo::VERSION()->getFullVersion(true)), - Uuid::fromString(Uuid::NIL), - false, - [], - 0, - GlobalItemTypeDictionary::getInstance()->getDictionary()->getEntries(), - )); + $this->session->sendDataPacket(StartGamePacket::create( + $this->player->getId(), + $this->player->getId(), + TypeConverter::getInstance()->coreGameModeToProtocol($this->player->getGamemode()), + $this->player->getOffsetPosition($location), + $location->pitch, + $location->yaw, + new CacheableNbt(CompoundTag::create()), //TODO: we don't care about this right now + $levelSettings, + "", + $this->server->getMotd(), + "", + false, + new PlayerMovementSettings(PlayerMovementType::SERVER_AUTHORITATIVE_V1, 0, false), + 0, + 0, + "", + true, + sprintf("%s %s", VersionInfo::NAME, VersionInfo::VERSION()->getFullVersion(true)), + Uuid::fromString(Uuid::NIL), + false, + [], + 0, + GlobalItemTypeDictionary::getInstance()->getDictionary()->getEntries(), + )); - $this->session->getLogger()->debug("Sending actor identifiers"); - $this->session->sendDataPacket(StaticPacketCache::getInstance()->getAvailableActorIdentifiers()); + $this->session->getLogger()->debug("Sending actor identifiers"); + $this->session->sendDataPacket(StaticPacketCache::getInstance()->getAvailableActorIdentifiers()); - $this->session->getLogger()->debug("Sending biome definitions"); - $this->session->sendDataPacket(StaticPacketCache::getInstance()->getBiomeDefs()); + $this->session->getLogger()->debug("Sending biome definitions"); + $this->session->sendDataPacket(StaticPacketCache::getInstance()->getBiomeDefs()); - $this->session->getLogger()->debug("Sending attributes"); - $this->session->getEntityEventBroadcaster()->syncAttributes([$this->session], $this->player, $this->player->getAttributeMap()->getAll()); + $this->session->getLogger()->debug("Sending attributes"); + $this->session->getEntityEventBroadcaster()->syncAttributes([$this->session], $this->player, $this->player->getAttributeMap()->getAll()); - $this->session->getLogger()->debug("Sending available commands"); - $this->session->syncAvailableCommands(); + $this->session->getLogger()->debug("Sending available commands"); + $this->session->syncAvailableCommands(); - $this->session->getLogger()->debug("Sending abilities"); - $this->session->syncAbilities($this->player); - $this->session->syncAdventureSettings(); + $this->session->getLogger()->debug("Sending abilities"); + $this->session->syncAbilities($this->player); + $this->session->syncAdventureSettings(); - $this->session->getLogger()->debug("Sending effects"); - foreach($this->player->getEffects()->all() as $effect){ - $this->session->getEntityEventBroadcaster()->onEntityEffectAdded([$this->session], $this->player, $effect, false); + $this->session->getLogger()->debug("Sending effects"); + foreach($this->player->getEffects()->all() as $effect){ + $this->session->getEntityEventBroadcaster()->onEntityEffectAdded([$this->session], $this->player, $effect, false); + } + + $this->session->getLogger()->debug("Sending actor metadata"); + $this->player->sendData([$this->player]); + + $this->session->getLogger()->debug("Sending inventory"); + $this->inventoryManager->syncAll(); + $this->inventoryManager->syncSelectedHotbarSlot(); + + $this->session->getLogger()->debug("Sending creative inventory data"); + $this->inventoryManager->syncCreative(); + + $this->session->getLogger()->debug("Sending crafting data"); + $this->session->sendDataPacket(CraftingDataCache::getInstance()->getCache($this->server->getCraftingManager())); + + $this->session->getLogger()->debug("Sending player list"); + $this->session->syncPlayerList($this->server->getOnlinePlayers()); + }finally{ + Timings::$playerNetworkSendPreSpawnGameData->stopTiming(); } - - $this->session->getLogger()->debug("Sending actor metadata"); - $this->player->sendData([$this->player]); - - $this->session->getLogger()->debug("Sending inventory"); - $this->inventoryManager->syncAll(); - $this->inventoryManager->syncSelectedHotbarSlot(); - - $this->session->getLogger()->debug("Sending creative inventory data"); - $this->inventoryManager->syncCreative(); - - $this->session->getLogger()->debug("Sending crafting data"); - $this->session->sendDataPacket(CraftingDataCache::getInstance()->getCache($this->server->getCraftingManager())); - - $this->session->getLogger()->debug("Sending player list"); - $this->session->syncPlayerList($this->server->getOnlinePlayers()); } public function handleRequestChunkRadius(RequestChunkRadiusPacket $packet) : bool{ diff --git a/src/player/Player.php b/src/player/Player.php index b2cd3bea6..dc33b75d3 100644 --- a/src/player/Player.php +++ b/src/player/Player.php @@ -1233,7 +1233,7 @@ class Player extends Human implements CommandSender, ChunkListener, IPlayer{ $revert = false; - if($distanceSquared > 100){ + if($distanceSquared > 225){ //15 blocks //TODO: this is probably too big if we process every movement /* !!! BEWARE YE WHO ENTER HERE !!! * @@ -1245,7 +1245,7 @@ class Player extends Human implements CommandSender, ChunkListener, IPlayer{ * If you must tamper with this code, be aware that this can cause very nasty results. Do not waste our time * asking for help if you suffer the consequences of messing with this. */ - $this->logger->debug("Moved too fast, reverting movement"); + $this->logger->debug("Moved too fast (" . sqrt($distanceSquared) . " blocks in 1 movement), reverting movement"); $this->logger->debug("Old position: " . $oldPos->asVector3() . ", new position: " . $newPos); $revert = true; }elseif(!$this->getWorld()->isInLoadedTerrain($newPos)){ diff --git a/src/timings/Timings.php b/src/timings/Timings.php index e38af9b46..9f011e3ed 100644 --- a/src/timings/Timings.php +++ b/src/timings/Timings.php @@ -34,7 +34,13 @@ use function get_class; use function str_starts_with; abstract class Timings{ + /** + * @deprecated This was used by the old timings viewer to make a timer appear in the Breakdown section of a timings + * report. Provide a group to your timer's constructor instead. + * @see Timings::GROUP_BREAKDOWN + */ public const INCLUDED_BY_OTHER_TIMINGS_PREFIX = "** "; + public const GROUP_BREAKDOWN = "Minecraft - Breakdown"; private static bool $initialized = false; @@ -50,6 +56,7 @@ abstract class Timings{ public static TimingsHandler $playerNetworkSendCompressSessionBuffer; public static TimingsHandler $playerNetworkSendEncrypt; public static TimingsHandler $playerNetworkSendInventorySync; + public static TimingsHandler $playerNetworkSendPreSpawnGameData; public static TimingsHandler $playerNetworkReceive; public static TimingsHandler $playerNetworkReceiveDecompress; public static TimingsHandler $playerNetworkReceiveDecrypt; @@ -125,8 +132,8 @@ abstract class Timings{ self::$initialized = true; self::$fullTick = new TimingsHandler("Full Server Tick"); - self::$serverTick = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Server Tick Update Cycle", self::$fullTick); - self::$serverInterrupts = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Server Mid-Tick Processing", self::$fullTick); + self::$serverTick = new TimingsHandler("Server Tick Update Cycle", self::$fullTick, group: self::GROUP_BREAKDOWN); + self::$serverInterrupts = new TimingsHandler("Server Mid-Tick Processing", self::$fullTick, group: self::GROUP_BREAKDOWN); self::$memoryManager = new TimingsHandler("Memory Manager"); self::$garbageCollector = new TimingsHandler("Garbage Collector", self::$memoryManager); self::$titleTick = new TimingsHandler("Console Title Tick"); @@ -134,21 +141,22 @@ abstract class Timings{ self::$connection = new TimingsHandler("Connection Handler"); self::$playerNetworkSend = new TimingsHandler("Player Network Send", self::$connection); - self::$playerNetworkSendCompress = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Player Network Send - Compression", self::$playerNetworkSend); - self::$playerNetworkSendCompressBroadcast = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Player Network Send - Compression (Broadcast)", self::$playerNetworkSendCompress); - self::$playerNetworkSendCompressSessionBuffer = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Player Network Send - Compression (Session Buffer)", self::$playerNetworkSendCompress); - self::$playerNetworkSendEncrypt = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Player Network Send - Encryption", self::$playerNetworkSend); - self::$playerNetworkSendInventorySync = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Player Network Send - Inventory Sync", self::$playerNetworkSend); + self::$playerNetworkSendCompress = new TimingsHandler("Player Network Send - Compression", self::$playerNetworkSend, group: self::GROUP_BREAKDOWN); + self::$playerNetworkSendCompressBroadcast = new TimingsHandler("Player Network Send - Compression (Broadcast)", self::$playerNetworkSendCompress, group: self::GROUP_BREAKDOWN); + self::$playerNetworkSendCompressSessionBuffer = new TimingsHandler("Player Network Send - Compression (Session Buffer)", self::$playerNetworkSendCompress, group: self::GROUP_BREAKDOWN); + self::$playerNetworkSendEncrypt = new TimingsHandler("Player Network Send - Encryption", self::$playerNetworkSend, group: self::GROUP_BREAKDOWN); + self::$playerNetworkSendInventorySync = new TimingsHandler("Player Network Send - Inventory Sync", self::$playerNetworkSend, group: self::GROUP_BREAKDOWN); + self::$playerNetworkSendPreSpawnGameData = new TimingsHandler("Player Network Send - Pre-Spawn Game Data", self::$playerNetworkSend, group: self::GROUP_BREAKDOWN); self::$playerNetworkReceive = new TimingsHandler("Player Network Receive", self::$connection); - self::$playerNetworkReceiveDecompress = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Player Network Receive - Decompression", self::$playerNetworkReceive); - self::$playerNetworkReceiveDecrypt = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Player Network Receive - Decryption", self::$playerNetworkReceive); + self::$playerNetworkReceiveDecompress = new TimingsHandler("Player Network Receive - Decompression", self::$playerNetworkReceive, group: self::GROUP_BREAKDOWN); + self::$playerNetworkReceiveDecrypt = new TimingsHandler("Player Network Receive - Decryption", self::$playerNetworkReceive, group: self::GROUP_BREAKDOWN); - self::$broadcastPackets = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Broadcast Packets", self::$playerNetworkSend); + self::$broadcastPackets = new TimingsHandler("Broadcast Packets", self::$playerNetworkSend, group: self::GROUP_BREAKDOWN); self::$playerMove = new TimingsHandler("Player Movement"); self::$playerChunkOrder = new TimingsHandler("Player Order Chunks"); - self::$playerChunkSend = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Player Network Send - Chunks", self::$playerNetworkSend); + self::$playerChunkSend = new TimingsHandler("Player Network Send - Chunks", self::$playerNetworkSend, group: self::GROUP_BREAKDOWN); self::$scheduler = new TimingsHandler("Scheduler"); self::$serverCommand = new TimingsHandler("Server Command"); self::$worldLoad = new TimingsHandler("World Load"); @@ -156,37 +164,37 @@ abstract class Timings{ self::$population = new TimingsHandler("World Population"); self::$generationCallback = new TimingsHandler("World Generation Callback"); self::$permissibleCalculation = new TimingsHandler("Permissible Calculation"); - self::$permissibleCalculationDiff = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Permissible Calculation - Diff", self::$permissibleCalculation); - self::$permissibleCalculationCallback = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Permissible Calculation - Callbacks", self::$permissibleCalculation); + self::$permissibleCalculationDiff = new TimingsHandler("Permissible Calculation - Diff", self::$permissibleCalculation, group: self::GROUP_BREAKDOWN); + self::$permissibleCalculationCallback = new TimingsHandler("Permissible Calculation - Callbacks", self::$permissibleCalculation, group: self::GROUP_BREAKDOWN); self::$syncPlayerDataLoad = new TimingsHandler("Player Data Load"); self::$syncPlayerDataSave = new TimingsHandler("Player Data Save"); - self::$entityMove = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Entity Movement"); - self::$entityMoveCollision = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Entity Movement - Collision Checks", self::$entityMove); + self::$entityMove = new TimingsHandler("Entity Movement", group: self::GROUP_BREAKDOWN); + self::$entityMoveCollision = new TimingsHandler("Entity Movement - Collision Checks", self::$entityMove, group: self::GROUP_BREAKDOWN); - self::$projectileMove = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Projectile Movement", self::$entityMove); - self::$projectileMoveRayTrace = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Projectile Movement - Ray Tracing", self::$projectileMove); + self::$projectileMove = new TimingsHandler("Projectile Movement", self::$entityMove, group: self::GROUP_BREAKDOWN); + self::$projectileMoveRayTrace = new TimingsHandler("Projectile Movement - Ray Tracing", self::$projectileMove, group: self::GROUP_BREAKDOWN); - self::$playerCheckNearEntities = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "checkNearEntities"); - self::$tickEntity = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Entity Tick"); - self::$tickTileEntity = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Block Entity Tick"); + self::$playerCheckNearEntities = new TimingsHandler("checkNearEntities", group: self::GROUP_BREAKDOWN); + self::$tickEntity = new TimingsHandler("Entity Tick", group: self::GROUP_BREAKDOWN); + self::$tickTileEntity = new TimingsHandler("Block Entity Tick", group: self::GROUP_BREAKDOWN); - self::$entityBaseTick = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Entity Base Tick"); - self::$livingEntityBaseTick = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Entity Base Tick - Living"); - self::$itemEntityBaseTick = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Entity Base Tick - ItemEntity"); + self::$entityBaseTick = new TimingsHandler("Entity Base Tick", group: self::GROUP_BREAKDOWN); + self::$livingEntityBaseTick = new TimingsHandler("Entity Base Tick - Living", group: self::GROUP_BREAKDOWN); + self::$itemEntityBaseTick = new TimingsHandler("Entity Base Tick - ItemEntity", group: self::GROUP_BREAKDOWN); - self::$schedulerSync = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Scheduler - Sync Tasks"); - self::$schedulerAsync = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Scheduler - Async Tasks"); + self::$schedulerSync = new TimingsHandler("Scheduler - Sync Tasks", group: self::GROUP_BREAKDOWN); + self::$schedulerAsync = new TimingsHandler("Scheduler - Async Tasks", group: self::GROUP_BREAKDOWN); - self::$playerCommand = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Player Command"); - self::$craftingDataCacheRebuild = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Build CraftingDataPacket Cache"); + self::$playerCommand = new TimingsHandler("Player Command", group: self::GROUP_BREAKDOWN); + self::$craftingDataCacheRebuild = new TimingsHandler("Build CraftingDataPacket Cache", group: self::GROUP_BREAKDOWN); } public static function getScheduledTaskTimings(TaskHandler $task, int $period) : TimingsHandler{ self::init(); - $name = "Task: " . $task->getOwnerName() . " Runnable: " . $task->getTaskName(); + $name = "Task: " . $task->getTaskName(); if($period > 0){ $name .= "(interval:" . $period . ")"; @@ -195,7 +203,7 @@ abstract class Timings{ } if(!isset(self::$pluginTaskTimingMap[$name])){ - self::$pluginTaskTimingMap[$name] = new TimingsHandler($name, self::$schedulerSync); + self::$pluginTaskTimingMap[$name] = new TimingsHandler($name, self::$schedulerSync, $task->getOwnerName()); } return self::$pluginTaskTimingMap[$name]; @@ -211,7 +219,7 @@ abstract class Timings{ if($entity instanceof Player && $reflect->getName() !== Player::class){ $entityType = "Player (" . $reflect->getName() . ")"; } - self::$entityTypeTimingMap[$entityType] = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Entity Tick - " . $entityType, self::$tickEntity); + self::$entityTypeTimingMap[$entityType] = new TimingsHandler("Entity Tick - " . $entityType, self::$tickEntity, group: self::GROUP_BREAKDOWN); } return self::$entityTypeTimingMap[$entityType]; @@ -221,7 +229,7 @@ abstract class Timings{ self::init(); $tileType = (new \ReflectionClass($tile))->getShortName(); if(!isset(self::$tileEntityTypeTimingMap[$tileType])){ - self::$tileEntityTypeTimingMap[$tileType] = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Block Entity Tick - " . $tileType, self::$tickTileEntity); + self::$tileEntityTypeTimingMap[$tileType] = new TimingsHandler("Block Entity Tick - " . $tileType, self::$tickTileEntity, group: self::GROUP_BREAKDOWN); } return self::$tileEntityTypeTimingMap[$tileType]; @@ -231,7 +239,7 @@ abstract class Timings{ self::init(); $pid = $pk->pid(); if(!isset(self::$packetReceiveTimingMap[$pid])){ - self::$packetReceiveTimingMap[$pid] = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Receive - " . $pk->getName(), self::$playerNetworkReceive); + self::$packetReceiveTimingMap[$pid] = new TimingsHandler("Receive - " . $pk->getName(), self::$playerNetworkReceive, group: self::GROUP_BREAKDOWN); } return self::$packetReceiveTimingMap[$pid]; @@ -240,24 +248,27 @@ abstract class Timings{ public static function getDecodeDataPacketTimings(ServerboundPacket $pk) : TimingsHandler{ $pid = $pk->pid(); return self::$packetDecodeTimingMap[$pid] ??= new TimingsHandler( - self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Decode - " . $pk->getName(), - self::getReceiveDataPacketTimings($pk) + "Decode - " . $pk->getName(), + self::getReceiveDataPacketTimings($pk), + group: self::GROUP_BREAKDOWN ); } public static function getHandleDataPacketTimings(ServerboundPacket $pk) : TimingsHandler{ $pid = $pk->pid(); return self::$packetHandleTimingMap[$pid] ??= new TimingsHandler( - self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Handler - " . $pk->getName(), - self::getReceiveDataPacketTimings($pk) + "Handler - " . $pk->getName(), + self::getReceiveDataPacketTimings($pk), + group: self::GROUP_BREAKDOWN ); } public static function getEncodeDataPacketTimings(ClientboundPacket $pk) : TimingsHandler{ $pid = $pk->pid(); return self::$packetEncodeTimingMap[$pid] ??= new TimingsHandler( - self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Encode - " . $pk->getName(), - self::getSendDataPacketTimings($pk) + "Encode - " . $pk->getName(), + self::getSendDataPacketTimings($pk), + group: self::GROUP_BREAKDOWN ); } @@ -265,7 +276,7 @@ abstract class Timings{ self::init(); $pid = $pk->pid(); if(!isset(self::$packetSendTimingMap[$pid])){ - self::$packetSendTimingMap[$pid] = new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Send - " . $pk->getName(), self::$playerNetworkSend); + self::$packetSendTimingMap[$pid] = new TimingsHandler("Send - " . $pk->getName(), self::$playerNetworkSend, group: self::GROUP_BREAKDOWN); } return self::$packetSendTimingMap[$pid]; @@ -274,7 +285,7 @@ abstract class Timings{ public static function getCommandDispatchTimings(string $commandName) : TimingsHandler{ self::init(); - return self::$commandTimingMap[$commandName] ??= new TimingsHandler(self::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Command - " . $commandName); + return self::$commandTimingMap[$commandName] ??= new TimingsHandler("Command - " . $commandName, group: self::GROUP_BREAKDOWN); } public static function getEventTimings(Event $event) : TimingsHandler{ diff --git a/src/timings/TimingsHandler.php b/src/timings/TimingsHandler.php index 231325c3e..b77610a65 100644 --- a/src/timings/TimingsHandler.php +++ b/src/timings/TimingsHandler.php @@ -32,6 +32,8 @@ use function implode; use function spl_object_id; class TimingsHandler{ + private const FORMAT_VERSION = 1; + private static bool $enabled = false; private static int $timingStart = 0; @@ -58,7 +60,9 @@ class TimingsHandler{ "Violations: " . $timings->getViolations(), "RecordId: " . $timings->getId(), "ParentRecordId: " . ($timings->getParentId() ?? "none"), - "TimerId: " . $timings->getTimerId() + "TimerId: " . $timings->getTimerId(), + "Ticks: " . $timings->getTicksActive(), + "Peak: " . $timings->getPeakTime(), ]); } $result = []; @@ -86,6 +90,7 @@ class TimingsHandler{ $result[] = "# Entities " . $entities; $result[] = "# LivingEntities " . $livingEntities; + $result[] = "# FormatVersion " . self::FORMAT_VERSION; $sampleTime = hrtime(true) - self::$timingStart; $result[] = "Sample time $sampleTime (" . ($sampleTime / 1000000000) . "s)"; diff --git a/src/timings/TimingsRecord.php b/src/timings/TimingsRecord.php index 84b2c8a2b..5254d2e7d 100644 --- a/src/timings/TimingsRecord.php +++ b/src/timings/TimingsRecord.php @@ -59,11 +59,17 @@ final class TimingsRecord{ public static function tick(bool $measure = true) : void{ if($measure){ foreach(self::$records as $record){ - if($record->curTickTotal > Server::TARGET_NANOSECONDS_PER_TICK){ - $record->violations += (int) floor($record->curTickTotal / Server::TARGET_NANOSECONDS_PER_TICK); + if($record->curCount > 0){ + if($record->curTickTotal > Server::TARGET_NANOSECONDS_PER_TICK){ + $record->violations += (int) floor($record->curTickTotal / Server::TARGET_NANOSECONDS_PER_TICK); + } + if($record->curTickTotal > $record->peakTime){ + $record->peakTime = $record->curTickTotal; + } + $record->curTickTotal = 0; + $record->curCount = 0; + $record->ticksActive++; } - $record->curTickTotal = 0; - $record->curCount = 0; } }else{ foreach(self::$records as $record){ @@ -82,6 +88,8 @@ final class TimingsRecord{ private int $totalTime = 0; private int $curTickTotal = 0; private int $violations = 0; + private int $ticksActive = 0; + private int $peakTime = 0; public function __construct( //I'm not the biggest fan of this cycle, but it seems to be the most effective way to avoid leaking anything. @@ -113,6 +121,10 @@ final class TimingsRecord{ public function getViolations() : int{ return $this->violations; } + public function getTicksActive() : int{ return $this->ticksActive; } + + public function getPeakTime() : float{ return $this->peakTime; } + public function startTiming(int $now) : void{ $this->start = $now; self::$currentRecord = $this; diff --git a/src/world/WorldTimings.php b/src/world/WorldTimings.php index e6a5d6d60..5a51f920b 100644 --- a/src/world/WorldTimings.php +++ b/src/world/WorldTimings.php @@ -53,27 +53,27 @@ class WorldTimings{ public function __construct(World $world){ $name = $world->getFolderName() . " - "; - $this->setBlock = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "setBlock"); - $this->doBlockLightUpdates = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Block Light Updates"); - $this->doBlockSkyLightUpdates = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Sky Light Updates"); + $this->setBlock = new TimingsHandler($name . "setBlock", group: Timings::GROUP_BREAKDOWN); + $this->doBlockLightUpdates = new TimingsHandler($name . "Block Light Updates", group: Timings::GROUP_BREAKDOWN); + $this->doBlockSkyLightUpdates = new TimingsHandler($name . "Sky Light Updates", group: Timings::GROUP_BREAKDOWN); - $this->doChunkUnload = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Unload Chunks"); - $this->scheduledBlockUpdates = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Scheduled Block Updates"); - $this->randomChunkUpdates = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Random Chunk Updates"); - $this->randomChunkUpdatesChunkSelection = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Random Chunk Updates - Chunk Selection"); - $this->doChunkGC = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Garbage Collection"); - $this->entityTick = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Tick Entities"); + $this->doChunkUnload = new TimingsHandler($name . "Unload Chunks", group: Timings::GROUP_BREAKDOWN); + $this->scheduledBlockUpdates = new TimingsHandler($name . "Scheduled Block Updates", group: Timings::GROUP_BREAKDOWN); + $this->randomChunkUpdates = new TimingsHandler($name . "Random Chunk Updates", group: Timings::GROUP_BREAKDOWN); + $this->randomChunkUpdatesChunkSelection = new TimingsHandler($name . "Random Chunk Updates - Chunk Selection", group: Timings::GROUP_BREAKDOWN); + $this->doChunkGC = new TimingsHandler($name . "Garbage Collection", group: Timings::GROUP_BREAKDOWN); + $this->entityTick = new TimingsHandler($name . "Tick Entities", group: Timings::GROUP_BREAKDOWN); Timings::init(); //make sure the timers we want are available - $this->syncChunkSend = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Player Send Chunks", Timings::$playerChunkSend); - $this->syncChunkSendPrepare = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Player Send Chunk Prepare", Timings::$playerChunkSend); + $this->syncChunkSend = new TimingsHandler($name . "Player Send Chunks", Timings::$playerChunkSend, group: Timings::GROUP_BREAKDOWN); + $this->syncChunkSendPrepare = new TimingsHandler($name . "Player Send Chunk Prepare", Timings::$playerChunkSend, group: Timings::GROUP_BREAKDOWN); - $this->syncChunkLoad = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Chunk Load", Timings::$worldLoad); - $this->syncChunkLoadData = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Chunk Load - Data"); - $this->syncChunkLoadFixInvalidBlocks = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Chunk Load - Fix Invalid Blocks"); - $this->syncChunkLoadEntities = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Chunk Load - Entities"); - $this->syncChunkLoadTileEntities = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Chunk Load - TileEntities"); - $this->syncChunkSave = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . $name . "Chunk Save", Timings::$worldSave); + $this->syncChunkLoad = new TimingsHandler($name . "Chunk Load", Timings::$worldLoad, group: Timings::GROUP_BREAKDOWN); + $this->syncChunkLoadData = new TimingsHandler($name . "Chunk Load - Data", group: Timings::GROUP_BREAKDOWN); + $this->syncChunkLoadFixInvalidBlocks = new TimingsHandler($name . "Chunk Load - Fix Invalid Blocks", group: Timings::GROUP_BREAKDOWN); + $this->syncChunkLoadEntities = new TimingsHandler($name . "Chunk Load - Entities", group: Timings::GROUP_BREAKDOWN); + $this->syncChunkLoadTileEntities = new TimingsHandler($name . "Chunk Load - TileEntities", group: Timings::GROUP_BREAKDOWN); + $this->syncChunkSave = new TimingsHandler($name . "Chunk Save", Timings::$worldSave, group: Timings::GROUP_BREAKDOWN); $this->doTick = new TimingsHandler($name . "World Tick"); }