Separated TimingsRecord from TimingsHandler (different lifetimes)

this fixes #3906.
TimingsHandler will now be automatically destroyed when there are no TimingsRecord referencing it and its owner has no references left to it.
TimingsRecord will be automatically destroyed at the end of the timings session (if active).

This fixes records from temporary timers being lost after the timings handlers are removed, while also fixing TimingsHandlers piling up regardless of whether timings are running or not.
This opens the doors to have more volatile timers, such as per-player/per-session timers, which are destroyed on player quit, but which won't result in the timings disappearing from the final timings result.
This commit is contained in:
Dylan K. Taylor 2020-12-03 15:45:49 +00:00
parent 29f6ed3f68
commit 5197707d32
4 changed files with 152 additions and 71 deletions

View File

@ -144,9 +144,6 @@ abstract class Command{
public function setLabel(string $name) : bool{
$this->nextLabel = $name;
if(!$this->isRegistered()){
if($this->timings instanceof TimingsHandler){
$this->timings->remove();
}
$this->timings = new TimingsHandler(Timings::INCLUDED_BY_OTHER_TIMINGS_PREFIX . "Command: " . $name);
$this->label = $name;

View File

@ -76,10 +76,6 @@ class RegisteredListener{
$this->timings->stopTiming();
}
public function __destruct(){
$this->timings->remove();
}
public function isHandlingCancelled() : bool{
return $this->handleCancelled;
}

View File

@ -29,13 +29,9 @@ use function count;
use function fwrite;
use function microtime;
use function round;
use function spl_object_id;
use const PHP_EOL;
class TimingsHandler{
/** @var TimingsHandler[] */
private static $HANDLERS = [];
/** @var bool */
private static $enabled = false;
/** @var float */
@ -47,16 +43,17 @@ class TimingsHandler{
public static function printTimings($fp) : void{
fwrite($fp, "Minecraft" . PHP_EOL);
foreach(self::$HANDLERS as $timings){
$time = $timings->totalTime;
$count = $timings->count;
foreach(TimingsRecord::getAll() as $timings){
$time = $timings->getTotalTime();
$count = $timings->getCount();
if($count === 0){
//this should never happen - a timings record shouldn't exist if it hasn't been used
continue;
}
$avg = $time / $count;
fwrite($fp, " " . $timings->name . " Time: " . round($time * 1000000000) . " Count: " . $count . " Avg: " . round($avg * 1000000000) . " Violations: " . $timings->violations . PHP_EOL);
fwrite($fp, " " . $timings->getName() . " Time: " . round($time * 1000000000) . " Count: " . $count . " Avg: " . round($avg * 1000000000) . " Violations: " . $timings->getViolations() . PHP_EOL);
}
fwrite($fp, "# Version " . Server::getInstance()->getVersion() . PHP_EOL);
@ -94,35 +91,15 @@ class TimingsHandler{
}
public static function reload() : void{
TimingsRecord::clearRecords();
if(self::$enabled){
foreach(self::$HANDLERS as $timings){
$timings->reset();
}
self::$timingStart = microtime(true);
}
}
public static function tick(bool $measure = true) : void{
if(self::$enabled){
if($measure){
foreach(self::$HANDLERS as $timings){
if($timings->curTickTotal > 0.05){
$timings->violations += (int) round($timings->curTickTotal / 0.05);
}
$timings->curTickTotal = 0;
$timings->curCount = 0;
$timings->timingDepth = 0;
}
}else{
foreach(self::$HANDLERS as $timings){
$timings->totalTime -= $timings->curTickTotal;
$timings->count -= $timings->curCount;
$timings->curTickTotal = 0;
$timings->curCount = 0;
$timings->timingDepth = 0;
}
}
TimingsRecord::tick($measure);
}
}
@ -131,27 +108,19 @@ class TimingsHandler{
/** @var TimingsHandler|null */
private $parent = null;
/** @var int */
private $count = 0;
/** @var int */
private $curCount = 0;
/** @var float */
private $start = 0;
/** @var TimingsRecord|null */
private $record = null;
/** @var int */
private $timingDepth = 0;
/** @var float */
private $totalTime = 0;
/** @var float */
private $curTickTotal = 0;
/** @var int */
private $violations = 0;
public function __construct(string $name, ?TimingsHandler $parent = null){
$this->name = $name;
$this->parent = $parent;
self::$HANDLERS[spl_object_id($this)] = $this;
}
public function getName() : string{ return $this->name; }
public function startTiming() : void{
if(self::$enabled){
$this->internalStartTiming(microtime(true));
@ -160,7 +129,10 @@ class TimingsHandler{
private function internalStartTiming(float $now) : void{
if(++$this->timingDepth === 1){
$this->start = $now;
if($this->record === null){
$this->record = new TimingsRecord($this);
}
$this->record->startTiming($now);
if($this->parent !== null){
$this->parent->internalStartTiming($now);
}
@ -180,16 +152,14 @@ class TimingsHandler{
//usefulness of bailing here anyway, we don't currently bother.
return;
}
if(--$this->timingDepth !== 0 or $this->start == 0){
if(--$this->timingDepth !== 0){
return;
}
$diff = $now - $this->start;
$this->totalTime += $diff;
$this->curTickTotal += $diff;
++$this->curCount;
++$this->count;
$this->start = 0;
if($this->record !== null){
//this might be null if a timings reset occurred while the timer was running
$this->record->stopTiming($now);
}
if($this->parent !== null){
$this->parent->internalStopTiming($now);
}
@ -211,17 +181,10 @@ class TimingsHandler{
}
}
public function reset() : void{
$this->count = 0;
$this->curCount = 0;
$this->violations = 0;
$this->curTickTotal = 0;
$this->totalTime = 0;
$this->start = 0;
$this->timingDepth = 0;
}
public function remove() : void{
unset(self::$HANDLERS[spl_object_id($this)]);
/**
* @internal
*/
public function destroyCycles() : void{
$this->record = null;
}
}

View File

@ -0,0 +1,125 @@
<?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\timings;
use function round;
use function spl_object_id;
/**
* Represents a record collected by a timings handler.
* This record will live until the end of the current timings session, even if its handler goes out of scope. This
* ensures that timings collected by destroyed timers are still shown in the final report.
*/
final class TimingsRecord{
/**
* @var self[]
* @phpstan-var array<int, self>
*/
private static $records = [];
public static function clearRecords() : void{
foreach(self::$records as $record){
$record->handler->destroyCycles();
}
self::$records = [];
}
/**
* @return self[]
* @phpstan-return array<int, self>
*/
public static function getAll() : array{ return self::$records; }
public static function tick(bool $measure = true) : void{
if($measure){
foreach(self::$records as $record){
if($record->curTickTotal > 0.05){
$record->violations += (int) round($record->curTickTotal / 0.05);
}
$record->curTickTotal = 0;
$record->curCount = 0;
}
}else{
foreach(self::$records as $record){
$record->totalTime -= $record->curTickTotal;
$record->count -= $record->curCount;
$record->curTickTotal = 0;
$record->curCount = 0;
}
}
}
/** @var TimingsHandler */
private $handler;
/** @var int */
private $count = 0;
/** @var int */
private $curCount = 0;
/** @var float */
private $start = 0;
/** @var float */
private $totalTime = 0;
/** @var float */
private $curTickTotal = 0;
/** @var int */
private $violations = 0;
public function __construct(TimingsHandler $handler){
self::$records[spl_object_id($this)] = $this;
//I'm not the biggest fan of this cycle, but it seems to be the most effective way to avoid leaking anything.
$this->handler = $handler;
}
public function getName() : string{ return $this->handler->getName(); }
public function getCount() : int{ return $this->count; }
public function getCurCount() : int{ return $this->curCount; }
public function getStart() : float{ return $this->start; }
public function getTotalTime() : float{ return $this->totalTime; }
public function getCurTickTotal() : float{ return $this->curTickTotal; }
public function getViolations() : int{ return $this->violations; }
public function startTiming(float $now) : void{
$this->start = $now;
}
public function stopTiming(float $now) : void{
if($this->start == 0){
return;
}
$diff = $now - $this->start;
$this->totalTime += $diff;
$this->curTickTotal += $diff;
++$this->curCount;
++$this->count;
$this->start = 0;
}
}