From 61560ec375f7ffbb705602a16775137ca5a63c2c Mon Sep 17 00:00:00 2001 From: "Dylan T." Date: Sun, 1 Dec 2024 14:49:27 +0000 Subject: [PATCH] Support for collecting timings from threads, and implement async task timings (#6333) The following callbacks can now be registered in timings, to allow threads to be notified of these events: - Turning on/off (`TimingsHandler::getToggleCallbacks()->add(...)`) - Reset (`TimingsHandler::getReloadCallbacks()->add(...)`) - Collect (`TimingsHandler::getCollectCallbacks()->add(...)`) Collect callbacks must return `list`. The promises must be `resolve()`d with `list` of printed timings records, as returned by `TimingsHandler::printCurrentThreadRecords()`. It's recommended to use 1 promise per thread. A timings report will be produced once all promises have been resolved. This system is used internally to collect timings for async tasks (closes #6166). For timings viewer developers: Timings format version has been bumped to 3 to accommodate this change. Timings groups should now include a `ThreadId` at the end of timings group names to ensure that their record IDs are segregated correctly, as they could otherwise conflict between threads. The main thread is not required to specify a thread ID. See pmmp/timings@13cefa6279ee8866dc584b9a7977a9c09cecd732 for implementation examples. New PHPStan error is caused by phpstan/phpstan#10924 --- composer.json | 2 +- composer.lock | 14 +-- src/Server.php | 34 ++++- src/command/defaults/TimingsCommand.php | 159 +++++++++++++----------- src/lang/KnownTranslationFactory.php | 4 + src/lang/KnownTranslationKeys.php | 1 + src/scheduler/AsyncTask.php | 10 +- src/scheduler/TimingsCollectionTask.php | 60 +++++++++ src/scheduler/TimingsControlTask.php | 60 +++++++++ src/timings/Timings.php | 21 ++++ src/timings/TimingsHandler.php | 133 +++++++++++++++++++- tests/phpstan/configs/phpstan-bugs.neon | 5 + 12 files changed, 410 insertions(+), 93 deletions(-) create mode 100644 src/scheduler/TimingsCollectionTask.php create mode 100644 src/scheduler/TimingsControlTask.php diff --git a/composer.json b/composer.json index 9747cb567..16bed54b7 100644 --- a/composer.json +++ b/composer.json @@ -41,7 +41,7 @@ "pocketmine/callback-validator": "^1.0.2", "pocketmine/color": "^0.3.0", "pocketmine/errorhandler": "^0.7.0", - "pocketmine/locale-data": "~2.21.0", + "pocketmine/locale-data": "~2.22.0", "pocketmine/log": "^0.4.0", "pocketmine/math": "~1.0.0", "pocketmine/nbt": "~1.0.0", diff --git a/composer.lock b/composer.lock index c1a0b0073..7eda66b35 100644 --- a/composer.lock +++ b/composer.lock @@ -4,7 +4,7 @@ "Read more about it at https://getcomposer.org/doc/01-basic-usage.md#installing-dependencies", "This file is @generated automatically" ], - "content-hash": "476374fb3d22e26a97c1dea8c6736faf", + "content-hash": "c57e8f52250edfd03906219fe14fc240", "packages": [ { "name": "adhocore/json-comment", @@ -420,16 +420,16 @@ }, { "name": "pocketmine/locale-data", - "version": "2.21.1", + "version": "2.22.0", "source": { "type": "git", "url": "https://github.com/pmmp/Language.git", - "reference": "fdba0f764d6281f64e5968dca94fdab96bf4e167" + "reference": "aed64e9ca92ffbb20788b3b3bb75b60e4f0eae2d" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/pmmp/Language/zipball/fdba0f764d6281f64e5968dca94fdab96bf4e167", - "reference": "fdba0f764d6281f64e5968dca94fdab96bf4e167", + "url": "https://api.github.com/repos/pmmp/Language/zipball/aed64e9ca92ffbb20788b3b3bb75b60e4f0eae2d", + "reference": "aed64e9ca92ffbb20788b3b3bb75b60e4f0eae2d", "shasum": "" }, "type": "library", @@ -437,9 +437,9 @@ "description": "Language resources used by PocketMine-MP", "support": { "issues": "https://github.com/pmmp/Language/issues", - "source": "https://github.com/pmmp/Language/tree/2.21.1" + "source": "https://github.com/pmmp/Language/tree/2.22.0" }, - "time": "2024-11-14T23:11:22+00:00" + "time": "2024-11-16T13:28:01+00:00" }, { "name": "pocketmine/log", diff --git a/src/Server.php b/src/Server.php index 074088068..9003a7f9c 100644 --- a/src/Server.php +++ b/src/Server.php @@ -89,6 +89,8 @@ use pocketmine\promise\Promise; use pocketmine\promise\PromiseResolver; use pocketmine\resourcepacks\ResourcePackManager; use pocketmine\scheduler\AsyncPool; +use pocketmine\scheduler\TimingsCollectionTask; +use pocketmine\scheduler\TimingsControlTask; use pocketmine\snooze\SleeperHandler; use pocketmine\stats\SendUsageTask; use pocketmine\thread\log\AttachableThreadSafeLogger; @@ -894,7 +896,36 @@ class Server{ $poolSize = max(1, (int) $poolSize); } + TimingsHandler::setEnabled($this->configGroup->getPropertyBool(Yml::SETTINGS_ENABLE_PROFILING, false)); + $this->profilingTickRate = $this->configGroup->getPropertyInt(Yml::SETTINGS_PROFILE_REPORT_TRIGGER, self::TARGET_TICKS_PER_SECOND); + $this->asyncPool = new AsyncPool($poolSize, max(-1, $this->configGroup->getPropertyInt(Yml::MEMORY_ASYNC_WORKER_HARD_LIMIT, 256)), $this->autoloader, $this->logger, $this->tickSleeper); + $this->asyncPool->addWorkerStartHook(function(int $i) : void{ + if(TimingsHandler::isEnabled()){ + $this->asyncPool->submitTaskToWorker(TimingsControlTask::setEnabled(true), $i); + } + }); + TimingsHandler::getToggleCallbacks()->add(function(bool $enable) : void{ + foreach($this->asyncPool->getRunningWorkers() as $workerId){ + $this->asyncPool->submitTaskToWorker(TimingsControlTask::setEnabled($enable), $workerId); + } + }); + TimingsHandler::getReloadCallbacks()->add(function() : void{ + foreach($this->asyncPool->getRunningWorkers() as $workerId){ + $this->asyncPool->submitTaskToWorker(TimingsControlTask::reload(), $workerId); + } + }); + TimingsHandler::getCollectCallbacks()->add(function() : array{ + $promises = []; + foreach($this->asyncPool->getRunningWorkers() as $workerId){ + $resolver = new PromiseResolver(); + $this->asyncPool->submitTaskToWorker(new TimingsCollectionTask($resolver), $workerId); + + $promises[] = $resolver->getPromise(); + } + + return $promises; + }); $netCompressionThreshold = -1; if($this->configGroup->getPropertyInt(Yml::NETWORK_BATCH_THRESHOLD, 256) >= 0){ @@ -968,9 +999,6 @@ class Server{ ))); $this->logger->info($this->language->translate(KnownTranslationFactory::pocketmine_server_license($this->getName()))); - TimingsHandler::setEnabled($this->configGroup->getPropertyBool(Yml::SETTINGS_ENABLE_PROFILING, false)); - $this->profilingTickRate = $this->configGroup->getPropertyInt(Yml::SETTINGS_PROFILE_REPORT_TRIGGER, self::TARGET_TICKS_PER_SECOND); - DefaultPermissions::registerCorePermissions(); $this->commandMap = new SimpleCommandMap($this); diff --git a/src/command/defaults/TimingsCommand.php b/src/command/defaults/TimingsCommand.php index 3c0701ea4..ec26f3efe 100644 --- a/src/command/defaults/TimingsCommand.php +++ b/src/command/defaults/TimingsCommand.php @@ -26,28 +26,28 @@ namespace pocketmine\command\defaults; use pocketmine\command\Command; use pocketmine\command\CommandSender; use pocketmine\command\utils\InvalidCommandSyntaxException; +use pocketmine\errorhandler\ErrorToExceptionHandler; use pocketmine\lang\KnownTranslationFactory; use pocketmine\permission\DefaultPermissionNames; use pocketmine\player\Player; use pocketmine\scheduler\BulkCurlTask; use pocketmine\scheduler\BulkCurlTaskOperation; use pocketmine\timings\TimingsHandler; +use pocketmine\utils\AssumptionFailedError; use pocketmine\utils\InternetException; use pocketmine\utils\InternetRequestResult; -use pocketmine\utils\Utils; use pocketmine\YmlServerProperties; use Symfony\Component\Filesystem\Path; use function count; use function fclose; use function file_exists; use function fopen; -use function fseek; use function fwrite; use function http_build_query; +use function implode; use function is_array; use function json_decode; use function mkdir; -use function stream_get_contents; use function strtolower; use const CURLOPT_AUTOREFERER; use const CURLOPT_FOLLOWLOCATION; @@ -101,82 +101,91 @@ class TimingsCommand extends VanillaCommand{ TimingsHandler::reload(); Command::broadcastCommandMessage($sender, KnownTranslationFactory::pocketmine_command_timings_reset()); }elseif($mode === "merged" || $mode === "report" || $paste){ - $timings = ""; - if($paste){ - $fileTimings = Utils::assumeNotFalse(fopen("php://temp", "r+b"), "Opening php://temp should never fail"); - }else{ - $index = 0; - $timingFolder = Path::join($sender->getServer()->getDataPath(), "timings"); - - if(!file_exists($timingFolder)){ - mkdir($timingFolder, 0777); - } - $timings = Path::join($timingFolder, "timings.txt"); - while(file_exists($timings)){ - $timings = Path::join($timingFolder, "timings" . (++$index) . ".txt"); - } - - $fileTimings = fopen($timings, "a+b"); - } - $lines = TimingsHandler::printTimings(); - foreach($lines as $line){ - fwrite($fileTimings, $line . PHP_EOL); - } - - if($paste){ - fseek($fileTimings, 0); - $data = [ - "browser" => $agent = $sender->getServer()->getName() . " " . $sender->getServer()->getPocketMineVersion(), - "data" => $content = stream_get_contents($fileTimings) - ]; - fclose($fileTimings); - - $host = $sender->getServer()->getConfigGroup()->getPropertyString(YmlServerProperties::TIMINGS_HOST, "timings.pmmp.io"); - - $sender->getServer()->getAsyncPool()->submitTask(new BulkCurlTask( - [new BulkCurlTaskOperation( - "https://$host?upload=true", - 10, - [], - [ - CURLOPT_HTTPHEADER => [ - "User-Agent: $agent", - "Content-Type: application/x-www-form-urlencoded" - ], - CURLOPT_POST => true, - CURLOPT_POSTFIELDS => http_build_query($data), - CURLOPT_AUTOREFERER => false, - CURLOPT_FOLLOWLOCATION => false - ] - )], - function(array $results) use ($sender, $host) : void{ - /** @phpstan-var array $results */ - if($sender instanceof Player && !$sender->isOnline()){ // TODO replace with a more generic API method for checking availability of CommandSender - return; - } - $result = $results[0]; - if($result instanceof InternetException){ - $sender->getServer()->getLogger()->logException($result); - return; - } - $response = json_decode($result->getBody(), true); - if(is_array($response) && isset($response["id"])){ - Command::broadcastCommandMessage($sender, KnownTranslationFactory::pocketmine_command_timings_timingsRead( - "https://" . $host . "/?id=" . $response["id"])); - }else{ - $sender->getServer()->getLogger()->debug("Invalid response from timings server (" . $result->getCode() . "): " . $result->getBody()); - Command::broadcastCommandMessage($sender, KnownTranslationFactory::pocketmine_command_timings_pasteError()); - } - } - )); - }else{ - fclose($fileTimings); - Command::broadcastCommandMessage($sender, KnownTranslationFactory::pocketmine_command_timings_timingsWrite($timings)); - } + $timingsPromise = TimingsHandler::requestPrintTimings(); + Command::broadcastCommandMessage($sender, KnownTranslationFactory::pocketmine_command_timings_collect()); + $timingsPromise->onCompletion( + fn(array $lines) => $paste ? $this->uploadReport($lines, $sender) : $this->createReportFile($lines, $sender), + fn() => throw new AssumptionFailedError("This promise is not expected to be rejected") + ); }else{ throw new InvalidCommandSyntaxException(); } return true; } + + /** + * @param string[] $lines + * @phpstan-param list $lines + */ + private function createReportFile(array $lines, CommandSender $sender) : void{ + $index = 0; + $timingFolder = Path::join($sender->getServer()->getDataPath(), "timings"); + + if(!file_exists($timingFolder)){ + mkdir($timingFolder, 0777); + } + $timings = Path::join($timingFolder, "timings.txt"); + while(file_exists($timings)){ + $timings = Path::join($timingFolder, "timings" . (++$index) . ".txt"); + } + + $fileTimings = ErrorToExceptionHandler::trapAndRemoveFalse(fn() => fopen($timings, "a+b")); + foreach($lines as $line){ + fwrite($fileTimings, $line . PHP_EOL); + } + fclose($fileTimings); + + Command::broadcastCommandMessage($sender, KnownTranslationFactory::pocketmine_command_timings_timingsWrite($timings)); + } + + /** + * @param string[] $lines + * @phpstan-param list $lines + */ + private function uploadReport(array $lines, CommandSender $sender) : void{ + $data = [ + "browser" => $agent = $sender->getServer()->getName() . " " . $sender->getServer()->getPocketMineVersion(), + "data" => implode("\n", $lines) + ]; + + $host = $sender->getServer()->getConfigGroup()->getPropertyString(YmlServerProperties::TIMINGS_HOST, "timings.pmmp.io"); + + $sender->getServer()->getAsyncPool()->submitTask(new BulkCurlTask( + [new BulkCurlTaskOperation( + "https://$host?upload=true", + 10, + [], + [ + CURLOPT_HTTPHEADER => [ + "User-Agent: $agent", + "Content-Type: application/x-www-form-urlencoded" + ], + CURLOPT_POST => true, + CURLOPT_POSTFIELDS => http_build_query($data), + CURLOPT_AUTOREFERER => false, + CURLOPT_FOLLOWLOCATION => false + ] + )], + function(array $results) use ($sender, $host) : void{ + /** @phpstan-var array $results */ + if($sender instanceof Player && !$sender->isOnline()){ // TODO replace with a more generic API method for checking availability of CommandSender + return; + } + $result = $results[0]; + if($result instanceof InternetException){ + $sender->getServer()->getLogger()->logException($result); + return; + } + $response = json_decode($result->getBody(), true); + if(is_array($response) && isset($response["id"])){ + Command::broadcastCommandMessage($sender, KnownTranslationFactory::pocketmine_command_timings_timingsRead( + "https://" . $host . "/?id=" . $response["id"])); + }else{ + $sender->getServer()->getLogger()->debug("Invalid response from timings server (" . $result->getCode() . "): " . $result->getBody()); + Command::broadcastCommandMessage($sender, KnownTranslationFactory::pocketmine_command_timings_pasteError()); + } + } + )); + } } diff --git a/src/lang/KnownTranslationFactory.php b/src/lang/KnownTranslationFactory.php index 8153a80d6..f0b70ffd1 100644 --- a/src/lang/KnownTranslationFactory.php +++ b/src/lang/KnownTranslationFactory.php @@ -1441,6 +1441,10 @@ final class KnownTranslationFactory{ return new Translatable(KnownTranslationKeys::POCKETMINE_COMMAND_TIMINGS_ALREADYENABLED, []); } + public static function pocketmine_command_timings_collect() : Translatable{ + return new Translatable(KnownTranslationKeys::POCKETMINE_COMMAND_TIMINGS_COLLECT, []); + } + public static function pocketmine_command_timings_description() : Translatable{ return new Translatable(KnownTranslationKeys::POCKETMINE_COMMAND_TIMINGS_DESCRIPTION, []); } diff --git a/src/lang/KnownTranslationKeys.php b/src/lang/KnownTranslationKeys.php index 4805d0c56..1c1fef20f 100644 --- a/src/lang/KnownTranslationKeys.php +++ b/src/lang/KnownTranslationKeys.php @@ -315,6 +315,7 @@ final class KnownTranslationKeys{ public const POCKETMINE_COMMAND_TIME_DESCRIPTION = "pocketmine.command.time.description"; public const POCKETMINE_COMMAND_TIME_USAGE = "pocketmine.command.time.usage"; public const POCKETMINE_COMMAND_TIMINGS_ALREADYENABLED = "pocketmine.command.timings.alreadyEnabled"; + public const POCKETMINE_COMMAND_TIMINGS_COLLECT = "pocketmine.command.timings.collect"; public const POCKETMINE_COMMAND_TIMINGS_DESCRIPTION = "pocketmine.command.timings.description"; public const POCKETMINE_COMMAND_TIMINGS_DISABLE = "pocketmine.command.timings.disable"; public const POCKETMINE_COMMAND_TIMINGS_ENABLE = "pocketmine.command.timings.enable"; diff --git a/src/scheduler/AsyncTask.php b/src/scheduler/AsyncTask.php index b0b64347a..33a0949d4 100644 --- a/src/scheduler/AsyncTask.php +++ b/src/scheduler/AsyncTask.php @@ -27,6 +27,7 @@ use pmmp\thread\Runnable; use pmmp\thread\ThreadSafe; use pmmp\thread\ThreadSafeArray; use pocketmine\thread\NonThreadSafeValue; +use pocketmine\timings\Timings; use function array_key_exists; use function igbinary_serialize; use function igbinary_unserialize; @@ -78,7 +79,14 @@ abstract class AsyncTask extends Runnable{ public function run() : void{ $this->result = null; - $this->onRun(); + $timings = Timings::getAsyncTaskRunTimings($this); + $timings->startTiming(); + + try{ + $this->onRun(); + }finally{ + $timings->stopTiming(); + } $this->finished = true; AsyncWorker::getNotifier()->wakeupSleeper(); diff --git a/src/scheduler/TimingsCollectionTask.php b/src/scheduler/TimingsCollectionTask.php new file mode 100644 index 000000000..25cd41166 --- /dev/null +++ b/src/scheduler/TimingsCollectionTask.php @@ -0,0 +1,60 @@ +> + */ +final class TimingsCollectionTask extends AsyncTask{ + private const TLS_KEY_RESOLVER = "resolver"; + + /** + * @phpstan-param PromiseResolver> $promiseResolver + */ + public function __construct(PromiseResolver $promiseResolver){ + $this->storeLocal(self::TLS_KEY_RESOLVER, $promiseResolver); + } + + public function onRun() : void{ + $this->setResult(TimingsHandler::printCurrentThreadRecords()); + } + + public function onCompletion() : void{ + /** + * @var string[] $result + * @phpstan-var list $result + */ + $result = $this->getResult(); + /** + * @var PromiseResolver $promiseResolver + * @phpstan-var PromiseResolver> $promiseResolver + */ + $promiseResolver = $this->fetchLocal(self::TLS_KEY_RESOLVER); + + $promiseResolver->resolve($result); + } +} diff --git a/src/scheduler/TimingsControlTask.php b/src/scheduler/TimingsControlTask.php new file mode 100644 index 000000000..51e906e6b --- /dev/null +++ b/src/scheduler/TimingsControlTask.php @@ -0,0 +1,60 @@ +operation === self::ENABLE){ + TimingsHandler::setEnabled(true); + \GlobalLogger::get()->debug("Enabled timings"); + }elseif($this->operation === self::DISABLE){ + TimingsHandler::setEnabled(false); + \GlobalLogger::get()->debug("Disabled timings"); + }elseif($this->operation === self::RELOAD){ + TimingsHandler::reload(); + \GlobalLogger::get()->debug("Reset timings"); + }else{ + throw new \InvalidArgumentException("Invalid operation $this->operation"); + } + } +} diff --git a/src/timings/Timings.php b/src/timings/Timings.php index 77f8efee6..8372e14c5 100644 --- a/src/timings/Timings.php +++ b/src/timings/Timings.php @@ -124,11 +124,16 @@ abstract class Timings{ /** @var TimingsHandler[] */ private static array $asyncTaskProgressUpdate = []; + /** @var TimingsHandler[] */ private static array $asyncTaskCompletion = []; /** @var TimingsHandler[] */ private static array $asyncTaskError = []; + private static TimingsHandler $asyncTaskWorkers; + /** @var TimingsHandler[] */ + private static array $asyncTaskRun = []; + public static function init() : void{ if(self::$initialized){ return; @@ -188,6 +193,8 @@ abstract class Timings{ self::$asyncTaskCompletionParent = new TimingsHandler("Async Tasks - Completion Handlers", self::$schedulerAsync); self::$asyncTaskErrorParent = new TimingsHandler("Async Tasks - Error Handlers", self::$schedulerAsync); + self::$asyncTaskWorkers = new TimingsHandler("Async Task Workers"); + self::$playerCommand = new TimingsHandler("Player Command"); self::$craftingDataCacheRebuild = new TimingsHandler("Build CraftingDataPacket Cache"); @@ -357,4 +364,18 @@ abstract class Timings{ return self::$asyncTaskError[$taskClass]; } + + public static function getAsyncTaskRunTimings(AsyncTask $task, string $group = self::GROUP_MINECRAFT) : TimingsHandler{ + $taskClass = $task::class; + if(!isset(self::$asyncTaskRun[$taskClass])){ + self::init(); + self::$asyncTaskRun[$taskClass] = new TimingsHandler( + "AsyncTask - " . self::shortenCoreClassName($taskClass, "pocketmine\\") . " - Run", + self::$asyncTaskWorkers, + $group + ); + } + + return self::$asyncTaskRun[$taskClass]; + } } diff --git a/src/timings/TimingsHandler.php b/src/timings/TimingsHandler.php index 574dd6d2b..95f7dbacc 100644 --- a/src/timings/TimingsHandler.php +++ b/src/timings/TimingsHandler.php @@ -23,20 +23,66 @@ declare(strict_types=1); namespace pocketmine\timings; +use pmmp\thread\Thread as NativeThread; +use pocketmine\promise\Promise; +use pocketmine\promise\PromiseResolver; use pocketmine\Server; +use pocketmine\utils\ObjectSet; use pocketmine\utils\Utils; +use function array_merge; +use function array_push; use function hrtime; use function implode; use function spl_object_id; +/** + * @phpstan-type CollectPromise Promise> + */ class TimingsHandler{ - private const FORMAT_VERSION = 2; //peak timings fix + private const FORMAT_VERSION = 3; //thread timings collection private static bool $enabled = false; private static int $timingStart = 0; - /** @return string[] */ - public static function printTimings() : array{ + /** @phpstan-var ObjectSet<\Closure(bool $enable) : void> */ + private static ?ObjectSet $toggleCallbacks = null; + /** @phpstan-var ObjectSet<\Closure() : void> */ + private static ?ObjectSet $reloadCallbacks = null; + /** @phpstan-var ObjectSet<\Closure() : list> */ + private static ?ObjectSet $collectCallbacks = null; + + /** + * @phpstan-template T of object + * @phpstan-param ?ObjectSet $where + * @phpstan-param-out ObjectSet $where + * @phpstan-return ObjectSet + */ + private static function lazyGetSet(?ObjectSet &$where) : ObjectSet{ + //workaround for phpstan bug - allows us to ignore 1 error instead of 6 without suppressing other errors + return $where ??= new ObjectSet(); + } + + /** + * @phpstan-return ObjectSet<\Closure(bool $enable) : void> + */ + public static function getToggleCallbacks() : ObjectSet{ return self::lazyGetSet(self::$toggleCallbacks); } + + /** + * @phpstan-return ObjectSet<\Closure() : void> + */ + public static function getReloadCallbacks() : ObjectSet{ return self::lazyGetSet(self::$reloadCallbacks); } + + /** + * @phpstan-return ObjectSet<\Closure() : list> + */ + public static function getCollectCallbacks() : ObjectSet{ return self::lazyGetSet(self::$collectCallbacks); } + + /** + * @return string[] + * @phpstan-return list + */ + public static function printCurrentThreadRecords() : array{ + $threadId = NativeThread::getCurrentThread()?->getThreadId(); $groups = []; foreach(TimingsRecord::getAll() as $timings){ @@ -49,7 +95,7 @@ class TimingsHandler{ $avg = $time / $count; - $group = $timings->getGroup(); + $group = $timings->getGroup() . ($threadId !== null ? " ThreadId: $threadId" : ""); $groups[$group][] = implode(" ", [ $timings->getName(), "Time: $time", @@ -72,6 +118,15 @@ class TimingsHandler{ } } + return $result; + } + + /** + * @return string[] + */ + private static function printFooter() : array{ + $result = []; + $result[] = "# Version " . Server::getInstance()->getVersion(); $result[] = "# " . Server::getInstance()->getName() . " " . Server::getInstance()->getPocketMineVersion(); @@ -79,29 +134,95 @@ class TimingsHandler{ $sampleTime = hrtime(true) - self::$timingStart; $result[] = "Sample time $sampleTime (" . ($sampleTime / 1000000000) . "s)"; + return $result; } + /** + * @deprecated This only collects timings from the main thread. Collecting timings from all threads is an async + * operation, so it can't be done synchronously. + * + * @return string[] + */ + public static function printTimings() : array{ + $records = self::printCurrentThreadRecords(); + $footer = self::printFooter(); + + return [...$records, ...$footer]; + } + + /** + * Collects timings asynchronously, allowing timings from multiple threads to be aggregated into a single report. + * + * NOTE: You need to add a callback to collectCallbacks if you want to include timings from other threads. They + * won't be automatically collected if you don't, since the main thread has no way to access them. + * + * This is an asynchronous operation, and the result is returned as a promise. + * The caller must add a callback to the returned promise to get the complete timings report. + * + * @phpstan-return Promise> + */ + public static function requestPrintTimings() : Promise{ + $thisThreadRecords = self::printCurrentThreadRecords(); + + $otherThreadRecordPromises = []; + if(self::$collectCallbacks !== null){ + foreach(self::$collectCallbacks as $callback){ + $callbackPromises = $callback(); + array_push($otherThreadRecordPromises, ...$callbackPromises); + } + } + + $resolver = new PromiseResolver(); + Promise::all($otherThreadRecordPromises)->onCompletion( + function(array $promisedRecords) use ($resolver, $thisThreadRecords) : void{ + $resolver->resolve([...$thisThreadRecords, ...array_merge(...$promisedRecords), ...self::printFooter()]); + }, + function() : void{ + throw new \AssertionError("This promise is not expected to be rejected"); + } + ); + + return $resolver->getPromise(); + } + public static function isEnabled() : bool{ return self::$enabled; } public static function setEnabled(bool $enable = true) : void{ + if($enable === self::$enabled){ + return; + } self::$enabled = $enable; - self::reload(); + self::internalReload(); + if(self::$toggleCallbacks !== null){ + foreach(self::$toggleCallbacks as $callback){ + $callback($enable); + } + } } public static function getStartTime() : float{ return self::$timingStart; } - public static function reload() : void{ + private static function internalReload() : void{ TimingsRecord::reset(); if(self::$enabled){ self::$timingStart = hrtime(true); } } + public static function reload() : void{ + self::internalReload(); + if(self::$reloadCallbacks !== null){ + foreach(self::$reloadCallbacks as $callback){ + $callback(); + } + } + } + public static function tick(bool $measure = true) : void{ if(self::$enabled){ TimingsRecord::tick($measure); diff --git a/tests/phpstan/configs/phpstan-bugs.neon b/tests/phpstan/configs/phpstan-bugs.neon index 6f2c94223..ea5e1c62a 100644 --- a/tests/phpstan/configs/phpstan-bugs.neon +++ b/tests/phpstan/configs/phpstan-bugs.neon @@ -90,6 +90,11 @@ parameters: count: 1 path: ../../../src/plugin/PluginManager.php + - + message: "#^Method pocketmine\\\\timings\\\\TimingsHandler\\:\\:lazyGetSet\\(\\) should return pocketmine\\\\utils\\\\ObjectSet\\ but returns pocketmine\\\\utils\\\\ObjectSet\\\\.$#" + count: 1 + path: ../../../src/timings/TimingsHandler.php + - message: "#^Casting to int something that's already int\\.$#" count: 1