From 006cdaf6ea7870d5876f384a944c60fa5a12760b Mon Sep 17 00:00:00 2001 From: "Dylan K. Taylor" Date: Sun, 26 Mar 2023 18:56:24 +0100 Subject: [PATCH 01/11] RakLibInterface: log the name of the session which triggered an unhandled exception this makes it easier to identify what sequence of events led up to the crash. --- src/network/mcpe/raklib/RakLibInterface.php | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/src/network/mcpe/raklib/RakLibInterface.php b/src/network/mcpe/raklib/RakLibInterface.php index d58819938..46927b4f6 100644 --- a/src/network/mcpe/raklib/RakLibInterface.php +++ b/src/network/mcpe/raklib/RakLibInterface.php @@ -192,6 +192,7 @@ class RakLibInterface implements ServerEventListener, AdvancedNetworkInterface{ $session = $this->sessions[$sessionId]; $address = $session->getIp(); $buf = substr($packet, 1); + $name = $session->getDisplayName(); try{ $session->handleEncoded($buf); }catch(PacketHandlingException $e){ @@ -204,6 +205,10 @@ class RakLibInterface implements ServerEventListener, AdvancedNetworkInterface{ $logger->debug(implode("\n", Utils::printableExceptionInfo($e))); $session->disconnect("Packet processing error (Error ID: $errorId)"); $this->interface->blockAddress($address, 5); + }catch(\Throwable $e){ + //record the name of the player who caused the crash, to make it easier to find the reproducing steps + $this->server->getLogger()->emergency("Crash occurred while handling a packet from session: $name"); + throw $e; } } } From eca9fe50b61d678a0e826b8864632ee169bdb710 Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" <49699333+dependabot[bot]@users.noreply.github.com> Date: Mon, 27 Mar 2023 13:03:30 +0100 Subject: [PATCH 02/11] Bump build/php from `a464454` to `9d8807b` (#5654) Bumps [build/php](https://github.com/pmmp/php-build-scripts) from `a464454` to `9d8807b`. - [Release notes](https://github.com/pmmp/php-build-scripts/releases) - [Commits](https://github.com/pmmp/php-build-scripts/compare/a464454d1ed946baabd32a02ddcf66361374b99c...9d8807be825b3fafd420534f2c29351c1bda6398) --- updated-dependencies: - dependency-name: build/php dependency-type: direct:production ... Signed-off-by: dependabot[bot] Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com> --- build/php | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/build/php b/build/php index a464454d1..9d8807be8 160000 --- a/build/php +++ b/build/php @@ -1 +1 @@ -Subproject commit a464454d1ed946baabd32a02ddcf66361374b99c +Subproject commit 9d8807be825b3fafd420534f2c29351c1bda6398 From 58974765a68f63a9968a7ff3a06f584ff2ee08d2 Mon Sep 17 00:00:00 2001 From: "Dylan K. Taylor" Date: Mon, 27 Mar 2023 13:03:01 +0100 Subject: [PATCH 03/11] InGamePacketHandler: fixed crash when attempting to drop more of an item than is available --- src/network/mcpe/handler/InGamePacketHandler.php | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/network/mcpe/handler/InGamePacketHandler.php b/src/network/mcpe/handler/InGamePacketHandler.php index 213ce2b8c..3e0825915 100644 --- a/src/network/mcpe/handler/InGamePacketHandler.php +++ b/src/network/mcpe/handler/InGamePacketHandler.php @@ -415,6 +415,9 @@ class InGamePacketHandler extends PacketHandler{ } $sourceSlotItem = $inventory->getItem($sourceSlot); + if($sourceSlotItem->getCount() < $droppedCount){ + return false; + } $serverItemStack = TypeConverter::getInstance()->coreItemStackToNet($sourceSlotItem); //because the client doesn't tell us the expected itemstack ID, we have to deep-compare our known //itemstack info with the one the client sent. This is costly, but we don't have any other option :( From 811639f2cdfead34cc0412f9fc76584661226ebf Mon Sep 17 00:00:00 2001 From: "Dylan K. Taylor" Date: Mon, 27 Mar 2023 13:26:14 +0100 Subject: [PATCH 04/11] InGamePacketHandler: relax errors on normal transactions to fix book editing for some reason book edits generate a transaction in addition to BookEditPacket. PM has never used the transaction, and it doesn't pass anyway because CreateItemAction can't be used in survival mode. However, since the strict validation introduced since ItemStackRequest, this dud transaction now causes the player to get kicked without these changes. --- .../mcpe/handler/InGamePacketHandler.php | 22 ++++++++++++++----- 1 file changed, 16 insertions(+), 6 deletions(-) diff --git a/src/network/mcpe/handler/InGamePacketHandler.php b/src/network/mcpe/handler/InGamePacketHandler.php index 3e0825915..6227e2a5a 100644 --- a/src/network/mcpe/handler/InGamePacketHandler.php +++ b/src/network/mcpe/handler/InGamePacketHandler.php @@ -377,13 +377,21 @@ class InGamePacketHandler extends PacketHandler{ } private function handleNormalTransaction(NormalTransactionData $data, int $itemStackRequestId) : bool{ - //When the ItemStackRequest system is used, this transaction type is only used for dropping items by pressing Q. + //When the ItemStackRequest system is used, this transaction type is used for dropping items by pressing Q. //I don't know why they don't just use ItemStackRequest for that too, which already supports dropping items by //clicking them outside an open inventory menu, but for now it is what it is. - //Fortunately, this means we can be extremely strict about the validation criteria. + //Fortunately, this means we can be much stricter about the validation criteria. - if(count($data->getActions()) > 2){ - throw new PacketHandlingException("Expected exactly 2 actions for dropping an item"); + $actionCount = count($data->getActions()); + if($actionCount > 2){ + if($actionCount > 5){ + throw new PacketHandlingException("Too many actions ($actionCount) in normal inventory transaction"); + } + + //Due to a bug in the game, this transaction type is still sent when a player edits a book. We don't need + //these transactions for editing books, since we have BookEditPacket, so we can just ignore them. + $this->session->getLogger()->debug("Ignoring normal inventory transaction with $actionCount actions (drop-item should have exactly 2 actions)"); + return false; } $sourceSlot = null; @@ -401,11 +409,13 @@ class InGamePacketHandler extends PacketHandler{ $sourceSlot = $networkInventoryAction->inventorySlot; $clientItemStack = $networkInventoryAction->oldItem->getItemStack(); }else{ - throw new PacketHandlingException("Unexpected action type in drop item transaction"); + $this->session->getLogger()->debug("Unexpected inventory action type $networkInventoryAction->sourceType in drop item transaction"); + return false; } } if($sourceSlot === null || $clientItemStack === null || $droppedCount === null){ - throw new PacketHandlingException("Missing information in drop item transaction, need source slot, client item stack and dropped count"); + $this->session->getLogger()->debug("Missing information in drop item transaction, need source slot, client item stack and dropped count"); + return false; } $inventory = $this->player->getInventory(); From 3ee62d84402ec92706defd4132ce137a59f5242b Mon Sep 17 00:00:00 2001 From: "Dylan K. Taylor" Date: Mon, 27 Mar 2023 15:44:42 +0100 Subject: [PATCH 05/11] InGamePacketHandler: increase max ItemStackRequest actions to 60 due to implementation quirks + some unforeseen ways these actions can behave, there can be as many as 53 actions in a single crafting request. This is an edge case, but it has to be catered for. --- src/network/mcpe/handler/InGamePacketHandler.php | 13 +++++++++++-- 1 file changed, 11 insertions(+), 2 deletions(-) diff --git a/src/network/mcpe/handler/InGamePacketHandler.php b/src/network/mcpe/handler/InGamePacketHandler.php index 6227e2a5a..5ee45347e 100644 --- a/src/network/mcpe/handler/InGamePacketHandler.php +++ b/src/network/mcpe/handler/InGamePacketHandler.php @@ -558,8 +558,17 @@ class InGamePacketHandler extends PacketHandler{ } private function handleSingleItemStackRequest(ItemStackRequest $request) : ItemStackResponse{ - if(count($request->getActions()) > 20){ - //TODO: we can probably lower this limit, but this will do for now + if(count($request->getActions()) > 60){ + //recipe book auto crafting can affect all slots of the inventory when consuming inputs or producing outputs + //this means there could be as many as 50 CraftingConsumeInput actions or Place (taking the result) actions + //in a single request (there are certain ways items can be arranged which will result in the same stack + //being taken from multiple times, but this is behaviour with a calculable limit) + //this means there SHOULD be AT MOST 53 actions in a single request, but 60 is a nice round number. + //n64Stacks = ? + //n1Stacks = 45 - n64Stacks + //nItemsRequiredFor1Craft = 9 + //nResults = floor((n1Stacks + (n64Stacks * 64)) / nItemsRequiredFor1Craft) + //nTakeActionsTotal = floor(64 / nResults) + max(1, 64 % nResults) + ((nResults * nItemsRequiredFor1Craft) - (n64Stacks * 64)) throw new PacketHandlingException("Too many actions in ItemStackRequest"); } $executor = new ItemStackRequestExecutor($this->player, $this->inventoryManager, $request); From af385668c2bb7b91595ef4d3f7edb90d854fb04f Mon Sep 17 00:00:00 2001 From: "Dylan K. Taylor" Date: Mon, 27 Mar 2023 17:55:39 +0100 Subject: [PATCH 06/11] InventoryManager: give more detailed information on failure to get info for held item --- src/network/mcpe/InventoryManager.php | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/src/network/mcpe/InventoryManager.php b/src/network/mcpe/InventoryManager.php index 35a45956b..a651b9213 100644 --- a/src/network/mcpe/InventoryManager.php +++ b/src/network/mcpe/InventoryManager.php @@ -576,9 +576,13 @@ class InventoryManager{ $playerInventory = $this->player->getInventory(); $selected = $playerInventory->getHeldItemIndex(); if($selected !== $this->clientSelectedHotbarSlot){ - $itemStackInfo = $this->getItemStackInfo($playerInventory, $selected); + $inventoryEntry = $this->inventories[spl_object_id($playerInventory)] ?? null; + if($inventoryEntry === null){ + throw new AssumptionFailedError("Player inventory should always be tracked"); + } + $itemStackInfo = $inventoryEntry->itemStackInfos[$selected] ?? null; if($itemStackInfo === null){ - throw new AssumptionFailedError("Player inventory slots should always be tracked"); + throw new AssumptionFailedError("Untracked player inventory slot $selected"); } $this->session->sendDataPacket(MobEquipmentPacket::create( From cd603e82663937fa6660c78842a657acfbcc4bab Mon Sep 17 00:00:00 2001 From: "Dylan K. Taylor" Date: Mon, 27 Mar 2023 18:03:16 +0100 Subject: [PATCH 07/11] Release 4.18.1 --- changelogs/4.18.md | 14 +++++++++++++- src/VersionInfo.php | 2 +- 2 files changed, 14 insertions(+), 2 deletions(-) diff --git a/changelogs/4.18.md b/changelogs/4.18.md index b7b7509a6..4007b206c 100644 --- a/changelogs/4.18.md +++ b/changelogs/4.18.md @@ -77,4 +77,16 @@ Released 25th March 2023. - Packet batch limit has been lowered to `100` packets. With the introduction of `ItemStackRequest`, this is more than sufficient for normal gameplay. ### Other -- Use `Vector3::zero()` instead of `new Vector3()` in some places. \ No newline at end of file +- Use `Vector3::zero()` instead of `new Vector3()` in some places. + +# 4.18.1 +Released 27th March 2023. + +## General +- `RakLibInterface` now logs the name of the currently active session if a crash occurs when processing a packet. This makes it easier to reproduce bugs, which is important to be able to fix them. +- Added more detailed debugging information to `InventoryManager->syncSelectedHotbarSlot()`. + +## Fixes +- Fixed server crash when attempting to drop more of an item from a stack than available in the inventory. +- Fixed packet processing errors when editing writable books. +- Fixed packet processing errors when shift-clicking on the recipe book to craft recipes which draw from a large number of inventory slots. \ No newline at end of file diff --git a/src/VersionInfo.php b/src/VersionInfo.php index 1f293e9a7..fcece5e89 100644 --- a/src/VersionInfo.php +++ b/src/VersionInfo.php @@ -32,7 +32,7 @@ use function str_repeat; final class VersionInfo{ public const NAME = "PocketMine-MP"; public const BASE_VERSION = "4.18.1"; - public const IS_DEVELOPMENT_BUILD = true; + public const IS_DEVELOPMENT_BUILD = false; public const BUILD_CHANNEL = "stable"; private function __construct(){ From beb0713a40ee2c07d47b0a3d9020616752ddf933 Mon Sep 17 00:00:00 2001 From: "Dylan K. Taylor" Date: Mon, 27 Mar 2023 18:03:17 +0100 Subject: [PATCH 08/11] 4.18.2 is next --- src/VersionInfo.php | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/VersionInfo.php b/src/VersionInfo.php index fcece5e89..14e4d3883 100644 --- a/src/VersionInfo.php +++ b/src/VersionInfo.php @@ -31,8 +31,8 @@ use function str_repeat; final class VersionInfo{ public const NAME = "PocketMine-MP"; - public const BASE_VERSION = "4.18.1"; - public const IS_DEVELOPMENT_BUILD = false; + public const BASE_VERSION = "4.18.2"; + public const IS_DEVELOPMENT_BUILD = true; public const BUILD_CHANNEL = "stable"; private function __construct(){ From b49a9ae81d4346ee5952d79a259207b03579f6dc Mon Sep 17 00:00:00 2001 From: "Dylan K. Taylor" Date: Tue, 28 Mar 2023 17:25:17 +0100 Subject: [PATCH 09/11] Added timings for calling events this gives a somewhat better overview of events, particularly if many plugins are subscribed to the same costly event (e.g. PlayerMoveEvent). In addition, it allows us to see the frequency that events are occurring. --- src/event/Event.php | 5 +++++ src/timings/Timings.php | 19 +++++++++++++++++++ 2 files changed, 24 insertions(+) diff --git a/src/event/Event.php b/src/event/Event.php index 7437283ac..df0f6bb03 100644 --- a/src/event/Event.php +++ b/src/event/Event.php @@ -26,6 +26,7 @@ declare(strict_types=1); */ namespace pocketmine\event; +use pocketmine\timings\Timings; use function get_class; abstract class Event{ @@ -51,6 +52,9 @@ abstract class Event{ throw new \RuntimeException("Recursive event call detected (reached max depth of " . self::MAX_EVENT_CALL_DEPTH . " calls)"); } + $timings = Timings::getEventTimings($this); + $timings->startTiming(); + $handlerList = HandlerListManager::global()->getListFor(get_class($this)); ++self::$eventCallDepth; @@ -67,6 +71,7 @@ abstract class Event{ } }finally{ --self::$eventCallDepth; + $timings->stopTiming(); } } } diff --git a/src/timings/Timings.php b/src/timings/Timings.php index 668860132..4525c217d 100644 --- a/src/timings/Timings.php +++ b/src/timings/Timings.php @@ -28,6 +28,8 @@ use pocketmine\entity\Entity; use pocketmine\network\mcpe\protocol\ClientboundPacket; use pocketmine\network\mcpe\protocol\ServerboundPacket; use pocketmine\scheduler\TaskHandler; +use function get_class; +use function str_starts_with; abstract class Timings{ public const INCLUDED_BY_OTHER_TIMINGS_PREFIX = "** "; @@ -153,6 +155,9 @@ abstract class Timings{ public static TimingsHandler $playerMove; + /** @var TimingsHandler[] */ + private static array $events = []; + public static function init() : void{ if(self::$initialized){ return; @@ -294,4 +299,18 @@ abstract class Timings{ return self::$packetSendTimingMap[$pid]; } + + public static function getEventTimings(Event $event) : TimingsHandler{ + $eventClass = get_class($event); + if(!isset(self::$events[$eventClass])){ + if(str_starts_with($eventClass, "pocketmine\\event\\")){ + $name = (new \ReflectionClass($event))->getShortName(); + }else{ + $name = $eventClass; + } + self::$events[$eventClass] = new TimingsHandler($name, group: "Events"); + } + + return self::$events[$eventClass]; + } } From 5e1f837a737466b00f1660b1b0d59f1cc03c7e54 Mon Sep 17 00:00:00 2001 From: "Dylan K. Taylor" Date: Tue, 28 Mar 2023 22:46:18 +0100 Subject: [PATCH 10/11] ... --- src/timings/Timings.php | 1 + 1 file changed, 1 insertion(+) diff --git a/src/timings/Timings.php b/src/timings/Timings.php index 4525c217d..c420f796f 100644 --- a/src/timings/Timings.php +++ b/src/timings/Timings.php @@ -25,6 +25,7 @@ namespace pocketmine\timings; use pocketmine\block\tile\Tile; use pocketmine\entity\Entity; +use pocketmine\event\Event; use pocketmine\network\mcpe\protocol\ClientboundPacket; use pocketmine\network\mcpe\protocol\ServerboundPacket; use pocketmine\scheduler\TaskHandler; From bed218d1ddfd1dd8b041107c42079656250402d8 Mon Sep 17 00:00:00 2001 From: "Dylan K. Taylor" Date: Wed, 29 Mar 2023 23:11:30 +0100 Subject: [PATCH 11/11] Fixed the first letter of event timing names getting trimmed off when src-namespace-prefix is not used --- src/plugin/PluginManager.php | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/plugin/PluginManager.php b/src/plugin/PluginManager.php index 09d98e5df..c7a4063fc 100644 --- a/src/plugin/PluginManager.php +++ b/src/plugin/PluginManager.php @@ -655,7 +655,7 @@ class PluginManager{ } $prefix = $plugin->getDescription()->getSrcNamespacePrefix(); - if(str_starts_with($handlerName, $prefix)){ + if(str_starts_with($handlerName, $prefix) && $prefix !== ""){ $handlerName = substr($handlerName, strlen($prefix) + 1); }