Async task timings

src/Server.php

@@ -89,6 +89,8 @@
 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;
@@ -891,7 +893,36 @@ public function __construct(
 				$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(new TimingsControlTask(TimingsControlTask::ENABLE), $i);
+				}
+			});
+			TimingsHandler::getToggleCallbacks()->add(function(bool $enable) : void{
+				foreach($this->asyncPool->getRunningWorkers() as $workerId){
+					$this->asyncPool->submitTaskToWorker(new TimingsControlTask($enable ? TimingsControlTask::ENABLE : TimingsControlTask::DISABLE), $workerId);
+				}
+			});
+			TimingsHandler::getResetCallbacks()->add(function() : void{
+				foreach($this->asyncPool->getRunningWorkers() as $workerId){
+					$this->asyncPool->submitTaskToWorker(new TimingsControlTask(TimingsControlTask::RESET), $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){
@@ -965,9 +996,6 @@ public function __construct(
 			)));
 			$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);

src/command/defaults/TimingsCommand.php

@@ -26,28 +26,28 @@
 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,92 @@ public function execute(CommandSender $sender, string $commandLabel, array $args
 			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<InternetRequestResult|InternetException> $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();
+			//TODO: i18n
+			Command::broadcastCommandMessage($sender, "Compiling timings report");
+			$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<string> $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<string> $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<InternetRequestResult|InternetException> $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());
+				}
+			}
+		));
+	}
 }

src/scheduler/AsyncTask.php

@@ -27,6 +27,7 @@
 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();

src/scheduler/TimingsCollectionTask.php

@@ -0,0 +1,61 @@
+<?php
+
+/*
+ *
+ *  ____            _        _   __  __ _                  __  __ ____
+ * |  _ \ ___   ___| | _____| |_|  \/  (_)_ __   ___      |  \/  |  _ \
+ * | |_) / _ \ / __| |/ / _ \ __| |\/| | | '_ \ / _ \_____| |\/| | |_) |
+ * |  __/ (_) | (__|   <  __/ |_| |  | | | | | |  __/_____| |  | |  __/
+ * |_|   \___/ \___|_|\_\___|\__|_|  |_|_|_| |_|\___|     |_|  |_|_|
+ *
+ * This program is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU Lesser General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ *
+ * @author PocketMine Team
+ * @link http://www.pocketmine.net/
+ *
+ *
+ */
+
+declare(strict_types=1);
+
+namespace pocketmine\scheduler;
+
+use pmmp\thread\Thread as NativeThread;
+use pocketmine\promise\PromiseResolver;
+use pocketmine\timings\TimingsHandler;
+
+/**
+ * @phpstan-type Resolver PromiseResolver<list<string>>
+ */
+final class TimingsCollectionTask extends AsyncTask{
+	private const TLS_KEY_RESOLVER = "resolver";
+
+	/**
+	 * @phpstan-param PromiseResolver<list<string>> $promiseResolver
+	 */
+	public function __construct(PromiseResolver $promiseResolver){
+		$this->storeLocal(self::TLS_KEY_RESOLVER, $promiseResolver);
+	}
+
+	public function onRun() : void{
+		$this->setResult(TimingsHandler::printCurrentThreadRecords(NativeThread::getCurrentThreadId()));
+	}
+
+	public function onCompletion() : void{
+		/**
+		 * @var string[] $result
+		 * @phpstan-var list<string> $result
+		 */
+		$result = $this->getResult();
+		/**
+		 * @var PromiseResolver $promiseResolver
+		 * @phpstan-var PromiseResolver<list<string>> $promiseResolver
+		 */
+		$promiseResolver = $this->fetchLocal(self::TLS_KEY_RESOLVER);
+
+		$promiseResolver->resolve($result);
+	}
+}

src/scheduler/TimingsControlTask.php

@@ -0,0 +1,52 @@
+<?php
+
+/*
+ *
+ *  ____            _        _   __  __ _                  __  __ ____
+ * |  _ \ ___   ___| | _____| |_|  \/  (_)_ __   ___      |  \/  |  _ \
+ * | |_) / _ \ / __| |/ / _ \ __| |\/| | | '_ \ / _ \_____| |\/| | |_) |
+ * |  __/ (_) | (__|   <  __/ |_| |  | | | | | |  __/_____| |  | |  __/
+ * |_|   \___/ \___|_|\_\___|\__|_|  |_|_|_| |_|\___|     |_|  |_|_|
+ *
+ * This program is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU Lesser General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ *
+ * @author PocketMine Team
+ * @link http://www.pocketmine.net/
+ *
+ *
+ */
+
+declare(strict_types=1);
+
+namespace pocketmine\scheduler;
+
+use pocketmine\timings\TimingsHandler;
+
+final class TimingsControlTask extends AsyncTask{
+
+	public const ENABLE = 1;
+	public const DISABLE = 2;
+	public const RESET = 3;
+
+	public function __construct(
+		private int $operation
+	){}
+
+	public function onRun() : void{
+		if($this->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::RESET){
+			TimingsHandler::reload();
+			\GlobalLogger::get()->debug("Reset timings");
+		}else{
+			throw new \InvalidArgumentException("Invalid operation $this->operation");
+		}
+	}
+}