From 9f3533d870c8c70fc3600166c3d6f950961b0ad5 Mon Sep 17 00:00:00 2001 From: "Dylan K. Taylor" Date: Wed, 13 Mar 2024 16:42:23 +0000 Subject: [PATCH] Improved logging for block decode errors this is still noisy, but less so than before. this also adds logging to places where it was previously missing. --- src/world/format/io/BaseWorldProvider.php | 32 ++++++++++++------- src/world/format/io/leveldb/LevelDB.php | 19 ++++++++--- src/world/format/io/region/Anvil.php | 5 +-- .../io/region/LegacyAnvilChunkTrait.php | 7 ++-- src/world/format/io/region/McRegion.php | 9 ++++-- src/world/format/io/region/PMAnvil.php | 5 +-- .../format/io/region/RegionWorldProvider.php | 4 +-- 7 files changed, 55 insertions(+), 26 deletions(-) diff --git a/src/world/format/io/BaseWorldProvider.php b/src/world/format/io/BaseWorldProvider.php index a4d8651a6..f863fdf74 100644 --- a/src/world/format/io/BaseWorldProvider.php +++ b/src/world/format/io/BaseWorldProvider.php @@ -31,7 +31,9 @@ use pocketmine\world\format\io\exception\CorruptedWorldException; use pocketmine\world\format\io\exception\UnsupportedWorldFormatException; use pocketmine\world\format\PalettedBlockArray; use pocketmine\world\WorldException; +use function count; use function file_exists; +use function implode; abstract class BaseWorldProvider implements WorldProvider{ protected WorldData $worldData; @@ -62,27 +64,35 @@ abstract class BaseWorldProvider implements WorldProvider{ */ abstract protected function loadLevelData() : WorldData; - private function translatePalette(PalettedBlockArray $blockArray) : PalettedBlockArray{ + private function translatePalette(PalettedBlockArray $blockArray, \Logger $logger) : PalettedBlockArray{ $palette = $blockArray->getPalette(); $newPalette = []; + $blockDecodeErrors = []; foreach($palette as $k => $legacyIdMeta){ //TODO: remember data for unknown states so we can implement them later + $id = $legacyIdMeta >> 4; + $meta = $legacyIdMeta & 0xf; try{ - $newStateData = $this->blockDataUpgrader->upgradeIntIdMeta($legacyIdMeta >> 4, $legacyIdMeta & 0xf); + $newStateData = $this->blockDataUpgrader->upgradeIntIdMeta($id, $meta); }catch(BlockStateDeserializeException $e){ + $blockDecodeErrors[] = "Palette offset $k / Failed to upgrade legacy ID/meta $id:$meta: " . $e->getMessage(); $newStateData = GlobalBlockStateHandlers::getUnknownBlockStateData(); } try{ $newPalette[$k] = $this->blockStateDeserializer->deserialize($newStateData); - }catch(BlockStateDeserializeException){ - //TODO: this needs to be logged - //TODO: maybe we can remember unknown states for later saving instead of discarding them and destroying maps... + }catch(BlockStateDeserializeException $e){ + //this should never happen anyway - if the upgrader returned an invalid state, we have bigger problems + $blockDecodeErrors[] = "Palette offset $k / Failed to deserialize upgraded state $id:$meta: " . $e->getMessage(); $newPalette[$k] = $this->blockStateDeserializer->deserialize(GlobalBlockStateHandlers::getUnknownBlockStateData()); } } + if(count($blockDecodeErrors) > 0){ + $logger->error("Errors decoding/upgrading blocks:\n - " . implode("\n - ", $blockDecodeErrors)); + } + //TODO: this is sub-optimal since it reallocates the offset table multiple times return PalettedBlockArray::fromData( $blockArray->getBitsPerBlock(), @@ -91,16 +101,16 @@ abstract class BaseWorldProvider implements WorldProvider{ ); } - protected function palettizeLegacySubChunkXZY(string $idArray, string $metaArray) : PalettedBlockArray{ - return $this->translatePalette(SubChunkConverter::convertSubChunkXZY($idArray, $metaArray)); + protected function palettizeLegacySubChunkXZY(string $idArray, string $metaArray, \Logger $logger) : PalettedBlockArray{ + return $this->translatePalette(SubChunkConverter::convertSubChunkXZY($idArray, $metaArray), $logger); } - protected function palettizeLegacySubChunkYZX(string $idArray, string $metaArray) : PalettedBlockArray{ - return $this->translatePalette(SubChunkConverter::convertSubChunkYZX($idArray, $metaArray)); + protected function palettizeLegacySubChunkYZX(string $idArray, string $metaArray, \Logger $logger) : PalettedBlockArray{ + return $this->translatePalette(SubChunkConverter::convertSubChunkYZX($idArray, $metaArray), $logger); } - protected function palettizeLegacySubChunkFromColumn(string $idArray, string $metaArray, int $yOffset) : PalettedBlockArray{ - return $this->translatePalette(SubChunkConverter::convertSubChunkFromLegacyColumn($idArray, $metaArray, $yOffset)); + protected function palettizeLegacySubChunkFromColumn(string $idArray, string $metaArray, int $yOffset, \Logger $logger) : PalettedBlockArray{ + return $this->translatePalette(SubChunkConverter::convertSubChunkFromLegacyColumn($idArray, $metaArray, $yOffset), $logger); } public function getPath() : string{ diff --git a/src/world/format/io/leveldb/LevelDB.php b/src/world/format/io/leveldb/LevelDB.php index 3d4f577a1..20b55922c 100644 --- a/src/world/format/io/leveldb/LevelDB.php +++ b/src/world/format/io/leveldb/LevelDB.php @@ -26,6 +26,7 @@ namespace pocketmine\world\format\io\leveldb; use pocketmine\block\Block; use pocketmine\data\bedrock\BiomeIds; use pocketmine\data\bedrock\block\BlockStateDeserializeException; +use pocketmine\data\bedrock\block\convert\UnsupportedBlockStateException; use pocketmine\nbt\LittleEndianNbtSerializer; use pocketmine\nbt\NBT; use pocketmine\nbt\NbtDataException; @@ -58,6 +59,7 @@ use function count; use function defined; use function extension_loaded; use function file_exists; +use function implode; use function is_dir; use function mkdir; use function ord; @@ -184,6 +186,8 @@ class LevelDB extends BaseWorldProvider implements WritableWorldProvider{ $paletteSize = $stream->getLInt(); } + $blockDecodeErrors = []; + for($i = 0; $i < $paletteSize; ++$i){ try{ $offset = $stream->getOffset(); @@ -199,18 +203,25 @@ class LevelDB extends BaseWorldProvider implements WritableWorldProvider{ $blockStateData = $this->blockDataUpgrader->upgradeBlockStateNbt($blockStateNbt); }catch(BlockStateDeserializeException $e){ //while not ideal, this is not a fatal error - $logger->error("Failed to upgrade blockstate: " . $e->getMessage() . " offset $i in palette, blockstate NBT: " . $blockStateNbt->toString()); + $blockDecodeErrors[] = "Palette offset $i / Upgrade error: " . $e->getMessage() . ", NBT: " . $blockStateNbt->toString(); $palette[] = $this->blockStateDeserializer->deserialize(GlobalBlockStateHandlers::getUnknownBlockStateData()); continue; } try{ $palette[] = $this->blockStateDeserializer->deserialize($blockStateData); + }catch(UnsupportedBlockStateException $e){ + $blockDecodeErrors[] = "Palette offset $i / " . $e->getMessage(); + $palette[] = $this->blockStateDeserializer->deserialize(GlobalBlockStateHandlers::getUnknownBlockStateData()); }catch(BlockStateDeserializeException $e){ - $logger->error("Failed to deserialize blockstate: " . $e->getMessage() . " offset $i in palette, blockstate NBT: " . $blockStateNbt->toString()); + $blockDecodeErrors[] = "Palette offset $i / Deserialize error: " . $e->getMessage() . ", NBT: " . $blockStateNbt->toString(); $palette[] = $this->blockStateDeserializer->deserialize(GlobalBlockStateHandlers::getUnknownBlockStateData()); } } + if(count($blockDecodeErrors) > 0){ + $logger->error("Errors decoding blocks:\n - " . implode("\n - ", $blockDecodeErrors)); + } + //TODO: exceptions return PalettedBlockArray::fromData($bitsPerBlock, $words, $palette); } @@ -443,7 +454,7 @@ class LevelDB extends BaseWorldProvider implements WritableWorldProvider{ $subChunks = []; for($yy = 0; $yy < 8; ++$yy){ - $storages = [$this->palettizeLegacySubChunkFromColumn($fullIds, $fullData, $yy)]; + $storages = [$this->palettizeLegacySubChunkFromColumn($fullIds, $fullData, $yy, new \PrefixedLogger($logger, "Subchunk y=$yy"))]; if(isset($convertedLegacyExtraData[$yy])){ $storages[] = $convertedLegacyExtraData[$yy]; } @@ -482,7 +493,7 @@ class LevelDB extends BaseWorldProvider implements WritableWorldProvider{ } } - $storages = [$this->palettizeLegacySubChunkXZY($blocks, $blockData)]; + $storages = [$this->palettizeLegacySubChunkXZY($blocks, $blockData, $logger)]; if($convertedLegacyExtraData !== null){ $storages[] = $convertedLegacyExtraData; } diff --git a/src/world/format/io/region/Anvil.php b/src/world/format/io/region/Anvil.php index abefc9f25..2c14b54e8 100644 --- a/src/world/format/io/region/Anvil.php +++ b/src/world/format/io/region/Anvil.php @@ -31,10 +31,11 @@ use pocketmine\world\format\SubChunk; class Anvil extends RegionWorldProvider{ use LegacyAnvilChunkTrait; - protected function deserializeSubChunk(CompoundTag $subChunk, PalettedBlockArray $biomes3d) : SubChunk{ + protected function deserializeSubChunk(CompoundTag $subChunk, PalettedBlockArray $biomes3d, \Logger $logger) : SubChunk{ return new SubChunk(Block::EMPTY_STATE_ID, [$this->palettizeLegacySubChunkYZX( self::readFixedSizeByteArray($subChunk, "Blocks", 4096), - self::readFixedSizeByteArray($subChunk, "Data", 2048) + self::readFixedSizeByteArray($subChunk, "Data", 2048), + $logger )], $biomes3d); //ignore legacy light information } diff --git a/src/world/format/io/region/LegacyAnvilChunkTrait.php b/src/world/format/io/region/LegacyAnvilChunkTrait.php index ba97d43b5..6e2f4c8f8 100644 --- a/src/world/format/io/region/LegacyAnvilChunkTrait.php +++ b/src/world/format/io/region/LegacyAnvilChunkTrait.php @@ -54,7 +54,7 @@ trait LegacyAnvilChunkTrait{ /** * @throws CorruptedChunkException */ - protected function deserializeChunk(string $data) : ?LoadedChunkData{ + protected function deserializeChunk(string $data, \Logger $logger) : ?LoadedChunkData{ $decompressed = @zlib_decode($data); if($decompressed === false){ throw new CorruptedChunkException("Failed to decompress chunk NBT"); @@ -90,7 +90,8 @@ trait LegacyAnvilChunkTrait{ $subChunksTag = $chunk->getListTag("Sections") ?? []; foreach($subChunksTag as $subChunk){ if($subChunk instanceof CompoundTag){ - $subChunks[$subChunk->getByte("Y")] = $this->deserializeSubChunk($subChunk, clone $biomes3d); + $y = $subChunk->getByte("Y"); + $subChunks[$y] = $this->deserializeSubChunk($subChunk, clone $biomes3d, new \PrefixedLogger($logger, "Subchunk y=$y")); } } for($y = Chunk::MIN_SUBCHUNK_INDEX; $y <= Chunk::MAX_SUBCHUNK_INDEX; ++$y){ @@ -111,6 +112,6 @@ trait LegacyAnvilChunkTrait{ ); } - abstract protected function deserializeSubChunk(CompoundTag $subChunk, PalettedBlockArray $biomes3d) : SubChunk; + abstract protected function deserializeSubChunk(CompoundTag $subChunk, PalettedBlockArray $biomes3d, \Logger $logger) : SubChunk; } diff --git a/src/world/format/io/region/McRegion.php b/src/world/format/io/region/McRegion.php index 878c84df4..ad6a2d7f2 100644 --- a/src/world/format/io/region/McRegion.php +++ b/src/world/format/io/region/McRegion.php @@ -46,7 +46,7 @@ class McRegion extends RegionWorldProvider{ /** * @throws CorruptedChunkException */ - protected function deserializeChunk(string $data) : ?LoadedChunkData{ + protected function deserializeChunk(string $data, \Logger $logger) : ?LoadedChunkData{ $decompressed = @zlib_decode($data); if($decompressed === false){ throw new CorruptedChunkException("Failed to decompress chunk NBT"); @@ -90,7 +90,12 @@ class McRegion extends RegionWorldProvider{ $fullData = self::readFixedSizeByteArray($chunk, "Data", 16384); for($y = 0; $y < 8; ++$y){ - $subChunks[$y] = new SubChunk(Block::EMPTY_STATE_ID, [$this->palettizeLegacySubChunkFromColumn($fullIds, $fullData, $y)], clone $biomes3d); + $subChunks[$y] = new SubChunk(Block::EMPTY_STATE_ID, [$this->palettizeLegacySubChunkFromColumn( + $fullIds, + $fullData, + $y, + new \PrefixedLogger($logger, "Subchunk y=$y"), + )], clone $biomes3d); } for($y = Chunk::MIN_SUBCHUNK_INDEX; $y <= Chunk::MAX_SUBCHUNK_INDEX; ++$y){ if(!isset($subChunks[$y])){ diff --git a/src/world/format/io/region/PMAnvil.php b/src/world/format/io/region/PMAnvil.php index 41dc0fa80..4fb463124 100644 --- a/src/world/format/io/region/PMAnvil.php +++ b/src/world/format/io/region/PMAnvil.php @@ -35,10 +35,11 @@ use pocketmine\world\format\SubChunk; class PMAnvil extends RegionWorldProvider{ use LegacyAnvilChunkTrait; - protected function deserializeSubChunk(CompoundTag $subChunk, PalettedBlockArray $biomes3d) : SubChunk{ + protected function deserializeSubChunk(CompoundTag $subChunk, PalettedBlockArray $biomes3d, \Logger $logger) : SubChunk{ return new SubChunk(Block::EMPTY_STATE_ID, [$this->palettizeLegacySubChunkXZY( self::readFixedSizeByteArray($subChunk, "Blocks", 4096), - self::readFixedSizeByteArray($subChunk, "Data", 2048) + self::readFixedSizeByteArray($subChunk, "Data", 2048), + $logger )], $biomes3d); } diff --git a/src/world/format/io/region/RegionWorldProvider.php b/src/world/format/io/region/RegionWorldProvider.php index a4a3055c6..1feca61be 100644 --- a/src/world/format/io/region/RegionWorldProvider.php +++ b/src/world/format/io/region/RegionWorldProvider.php @@ -147,7 +147,7 @@ abstract class RegionWorldProvider extends BaseWorldProvider{ /** * @throws CorruptedChunkException */ - abstract protected function deserializeChunk(string $data) : ?LoadedChunkData; + abstract protected function deserializeChunk(string $data, \Logger $logger) : ?LoadedChunkData; /** * @return CompoundTag[] @@ -200,7 +200,7 @@ abstract class RegionWorldProvider extends BaseWorldProvider{ $chunkData = $this->loadRegion($regionX, $regionZ)->readChunk($chunkX & 0x1f, $chunkZ & 0x1f); if($chunkData !== null){ - return $this->deserializeChunk($chunkData); + return $this->deserializeChunk($chunkData, new \PrefixedLogger($this->logger, "Loading chunk x=$chunkX z=$chunkZ")); } return null;