diff --git a/src/timings/TimingsHandler.php b/src/timings/TimingsHandler.php index 3cf65c203..231325c3e 100644 --- a/src/timings/TimingsHandler.php +++ b/src/timings/TimingsHandler.php @@ -28,6 +28,8 @@ use pocketmine\Server; use pocketmine\utils\Utils; use function count; use function hrtime; +use function implode; +use function spl_object_id; class TimingsHandler{ private static bool $enabled = false; @@ -48,7 +50,16 @@ class TimingsHandler{ $avg = $time / $count; $group = $timings->getGroup(); - $groups[$group][] = $timings->getName() . " Time: $time Count: " . $count . " Avg: $avg Violations: " . $timings->getViolations(); + $groups[$group][] = implode(" ", [ + $timings->getName(), + "Time: $time", + "Count: $count", + "Avg: $avg", + "Violations: " . $timings->getViolations(), + "RecordId: " . $timings->getId(), + "ParentRecordId: " . ($timings->getParentId() ?? "none"), + "TimerId: " . $timings->getTimerId() + ]); } $result = []; @@ -107,9 +118,15 @@ class TimingsHandler{ } } - private ?TimingsRecord $record = null; + private ?TimingsRecord $rootRecord = null; private int $timingDepth = 0; + /** + * @var TimingsRecord[] + * @phpstan-var array + */ + private array $recordsByParent = []; + public function __construct( private string $name, private ?TimingsHandler $parent = null, @@ -128,13 +145,24 @@ class TimingsHandler{ private function internalStartTiming(int $now) : void{ if(++$this->timingDepth === 1){ - if($this->record === null){ - $this->record = new TimingsRecord($this); - } - $this->record->startTiming($now); if($this->parent !== null){ $this->parent->internalStartTiming($now); } + + $current = TimingsRecord::getCurrentRecord(); + if($current !== null){ + $record = $this->recordsByParent[spl_object_id($current)] ?? null; + if($record === null){ + $record = new TimingsRecord($this, $current); + $this->recordsByParent[spl_object_id($current)] = $record; + } + }else{ + if($this->rootRecord === null){ + $this->rootRecord = new TimingsRecord($this, null); + } + $record = $this->rootRecord; + } + $record->startTiming($now); } } @@ -155,9 +183,12 @@ class TimingsHandler{ return; } - if($this->record !== null){ - //this might be null if a timings reset occurred while the timer was running - $this->record->stopTiming($now); + $record = TimingsRecord::getCurrentRecord(); + if($record !== null){ + if($record->getTimerId() !== spl_object_id($this)){ + throw new \LogicException("Timer \"" . $record->getName() . "\" should have been stopped before stopping timer \"" . $this->name . "\""); + } + $record->stopTiming($now); } if($this->parent !== null){ $this->parent->internalStopTiming($now); @@ -184,6 +215,7 @@ class TimingsHandler{ * @internal */ public function destroyCycles() : void{ - $this->record = null; + $this->rootRecord = null; + $this->recordsByParent = []; } } diff --git a/src/timings/TimingsRecord.php b/src/timings/TimingsRecord.php index 8449a7e8d..891f41b3f 100644 --- a/src/timings/TimingsRecord.php +++ b/src/timings/TimingsRecord.php @@ -24,6 +24,7 @@ declare(strict_types=1); namespace pocketmine\timings; use pocketmine\Server; +use pocketmine\utils\AssumptionFailedError; use function round; use function spl_object_id; @@ -39,11 +40,14 @@ final class TimingsRecord{ */ private static array $records = []; + private static ?self $currentRecord = null; + public static function clearRecords() : void{ foreach(self::$records as $record){ $record->handler->destroyCycles(); } self::$records = []; + self::$currentRecord = null; } /** @@ -81,11 +85,18 @@ final class TimingsRecord{ 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. - private TimingsHandler $handler + private TimingsHandler $handler, + private ?TimingsRecord $parentRecord ){ self::$records[spl_object_id($this)] = $this; } + public function getId() : int{ return spl_object_id($this); } + + public function getParentId() : ?int{ return $this->parentRecord?->getId(); } + + public function getTimerId() : int{ return spl_object_id($this->handler); } + public function getName() : string{ return $this->handler->getName(); } public function getGroup() : string{ return $this->handler->getGroup(); } @@ -104,12 +115,22 @@ final class TimingsRecord{ public function startTiming(int $now) : void{ $this->start = $now; + self::$currentRecord = $this; } public function stopTiming(int $now) : void{ if($this->start == 0){ return; } + if(self::$currentRecord !== $this){ + if(self::$currentRecord === null){ + //timings may have been stopped while this timer was running + return; + } + + throw new AssumptionFailedError("stopTiming() called on a non-current timer"); + } + self::$currentRecord = $this->parentRecord; $diff = $now - $this->start; $this->totalTime += $diff; $this->curTickTotal += $diff; @@ -117,4 +138,8 @@ final class TimingsRecord{ ++$this->count; $this->start = 0; } + + public static function getCurrentRecord() : ?self{ + return self::$currentRecord; + } }