X-Git-Url: https://git.mxchange.org/?a=blobdiff_plain;f=src%2FUtil%2FProfiler.php;h=7e04ee563f6afe3744b6ae9116baad09f186b8e1;hb=39c2282c1292af173f854e2a4338c601f9ba58f6;hp=7bf30a2775d95cbecdba49e75a3d8aca4c77fd64;hpb=5e6e1a80250a9b03a0689bbda92a6a66140cc669;p=friendica.git

diff --git a/src/Util/Profiler.php b/src/Util/Profiler.php
index 7bf30a2775..7e04ee563f 100644
--- a/src/Util/Profiler.php
+++ b/src/Util/Profiler.php
@@ -1,8 +1,29 @@
 <?php
+/**
+ * @copyright Copyright (C) 2010-2021, the Friendica project
+ *
+ * @license GNU AGPL version 3 or any later version
+ *
+ * This program is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU Affero General Public License as
+ * published by the Free Software Foundation, either version 3 of the
+ * License, or (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU Affero General Public License for more details.
+ *
+ * You should have received a copy of the GNU Affero General Public License
+ * along with this program.  If not, see <https://www.gnu.org/licenses/>.
+ *
+ */
 
 namespace Friendica\Util;
 
-use Friendica\Core;
+use Friendica\Core\Config\ValueObject\Cache;
+use Friendica\Core\Config\Capability\IManageConfigValues;
+use Friendica\Core\System;
 use Psr\Container\ContainerExceptionInterface;
 use Psr\Container\ContainerInterface;
 use Psr\Container\NotFoundExceptionInterface;
@@ -12,7 +33,7 @@ use Psr\Log\LoggerInterface;
  * A class to store profiling data
  * It can handle different logging data for specific functions or global performance measures
  *
- * It stores the data as log entries (@see LoggerInterface )
+ * It stores the data as log entries (@see LoggerInterface)
  */
 class Profiler implements ContainerInterface
 {
@@ -33,39 +54,109 @@ class Profiler implements ContainerInterface
 	 */
 	private $rendertime;
 
+	private $timestamps = [];
+
 	/**
-	 * @var LoggerInterface The profiler logger
+	 * True, if the Profiler should measure the whole rendertime including functions
+	 *
+	 * @return bool
 	 */
-	private $logger;
+	public function isRendertime()
+	{
+		return $this->rendertime;
+	}
 
 	/**
-	 * @param LoggerInterface $logger The profiler logger
-	 * @param bool $enabled           True, if the Profiler is enabled
-	 * @param bool $renderTime        True, if the Profiler should measure the whole rendertime including functions
+	 * Updates the enabling of the current profiler
+	 *
+	 * @param IManageConfigValues $config
 	 */
-	public function __construct(LoggerInterface $logger, $enabled = false, $renderTime = false)
+	public function update(IManageConfigValues $config)
 	{
-		$this->enabled = $enabled;
-		$this->rendertime = $renderTime;
-		$this->logger = $logger;
-		$this->performance = [];
-		$this->callstack   = [];
+		$this->enabled = $config->get('system', 'profiler');
+		$this->rendertime = $config->get('rendertime', 'callstack');
+	}
+
+	/**
+	 * @param \Friendica\Core\Config\ValueObject\Cache $configCache The configuration cache
+	 */
+	public function __construct(Cache $configCache)
+	{
+		$this->enabled = $configCache->get('system', 'profiler');
+		$this->rendertime = $configCache->get('rendertime', 'callstack');
+		$this->reset();
+	}
+
+	/**
+	 * Start a profiler recording
+	 *
+	 * @param string $value
+	 * @return void
+	 */
+	public function startRecording(string $value)
+	{
+		if (!$this->enabled) {
+			return;
+		}
+
+		$this->timestamps[] = ['value' => $value, 'stamp' => microtime(true), 'credit' => 0];
+	}
+
+	/**
+	 * Stop a profiler recording
+	 *
+	 * @param string $callstack
+	 * @return void
+	 */
+	public function stopRecording(string $callstack = '')
+	{
+		if (!$this->enabled || empty($this->timestamps)) {
+			return;
+		}
+
+		$timestamp = array_pop($this->timestamps);
+
+		$duration = floatval(microtime(true) - $timestamp['stamp'] - $timestamp['credit']);
+		$value = $timestamp['value'];
+
+		foreach ($this->timestamps as $key => $stamp) {
+			$this->timestamps[$key]['credit'] += $duration;
+		}
+
+		$callstack = $callstack ?: System::callstack(4, $value == 'rendering' ? 0 : 1);
+
+		if (!isset($this->performance[$value])) {
+			$this->performance[$value] = 0;
+		}
+
+		$this->performance[$value] += (float) $duration;
+		$this->performance['marktime'] += (float) $duration;
+
+		if (!isset($this->callstack[$value][$callstack])) {
+			// Prevent ugly E_NOTICE
+			$this->callstack[$value][$callstack] = 0;
+		}
+
+		$this->callstack[$value][$callstack] += (float) $duration;
 	}
 
 	/**
 	 * Saves a timestamp for a value - f.e. a call
 	 * Necessary for profiling Friendica
 	 *
-	 * @param int $timestamp the Timestamp
-	 * @param string $value A value to profile
+	 * @param int    $timestamp the Timestamp
+	 * @param string $value     A value to profile
+	 * @param string $callstack A callstack string, generated if absent
 	 */
-	public function saveTimestamp($timestamp, $value)
+	public function saveTimestamp($timestamp, $value, $callstack = '')
 	{
 		if (!$this->enabled) {
 			return;
 		}
 
-		$duration = (float) (microtime(true) - $timestamp);
+		$callstack = $callstack ?: System::callstack(4, 1);
+
+		$duration = floatval(microtime(true) - $timestamp);
 
 		if (!isset($this->performance[$value])) {
 			// Prevent ugly E_NOTICE
@@ -75,8 +166,6 @@ class Profiler implements ContainerInterface
 		$this->performance[$value] += (float) $duration;
 		$this->performance['marktime'] += (float) $duration;
 
-		$callstack = Core\System::callstack();
-
 		if (!isset($this->callstack[$value][$callstack])) {
 			// Prevent ugly E_NOTICE
 			$this->callstack[$value][$callstack] = 0;
@@ -87,131 +176,155 @@ class Profiler implements ContainerInterface
 
 	/**
 	 * Resets the performance and callstack profiling
-	 *
-	 * @param bool $performance If true, reset the performance (Default true)
-	 * @param bool $callstack   If true, reset the callstack (Default true)
 	 */
-	public function reset($performance = true, $callstack = true)
+	public function reset()
 	{
-		if ($performance) {
-			$this->performance = [];
-			$this->performance['start'] = microtime(true);
-			$this->performance['database'] = 0;
-			$this->performance['database_write'] = 0;
-			$this->performance['cache'] = 0;
-			$this->performance['cache_write'] = 0;
-			$this->performance['network'] = 0;
-			$this->performance['file'] = 0;
-			$this->performance['rendering'] = 0;
-			$this->performance['parser'] = 0;
-			$this->performance['marktime'] = 0;
-			$this->performance['markstart'] = microtime(true);
-		}
-
-		if ($callstack) {
-			$this->callstack['database'] = [];
-			$this->callstack['database_write'] = [];
-			$this->callstack['cache'] = [];
-			$this->callstack['cache_write'] = [];
-			$this->callstack['network'] = [];
-			$this->callstack['file'] = [];
-			$this->callstack['rendering'] = [];
-			$this->callstack['parser'] = [];
-		}
+		$this->resetPerformance();
+		$this->resetCallstack();
 	}
 
 	/**
-	 * Save the current profiling data to a log entry
+	 * Resets the performance profiling data
+	 */
+	public function resetPerformance()
+	{
+		$this->performance = [];
+		$this->performance['start'] = microtime(true);
+		$this->performance['ready'] = 0;
+		$this->performance['database'] = 0;
+		$this->performance['database_write'] = 0;
+		$this->performance['cache'] = 0;
+		$this->performance['cache_write'] = 0;
+		$this->performance['network'] = 0;
+		$this->performance['file'] = 0;
+		$this->performance['rendering'] = 0;
+		$this->performance['session'] = 0;
+		$this->performance['marktime'] = 0;
+		$this->performance['marktime'] = microtime(true);
+		$this->performance['classcreate'] = 0;
+		$this->performance['classinit'] = 0;
+		$this->performance['init'] = 0;
+		$this->performance['content'] = 0;
+	}
+
+	/**
+	 * Resets the callstack profiling data
+	 */
+	public function resetCallstack()
+	{
+		$this->callstack = [];
+		$this->callstack['database'] = [];
+		$this->callstack['database_write'] = [];
+		$this->callstack['cache'] = [];
+		$this->callstack['cache_write'] = [];
+		$this->callstack['network'] = [];
+		$this->callstack['file'] = [];
+		$this->callstack['rendering'] = [];
+		$this->callstack['session'] = [];
+	}
+
+	/**
+	 * Returns the rendertime string
+	 * @param float $limit Minimal limit for displaying the execution duration
 	 *
-	 * @param string $message Additional message for the log
+	 * @return string the rendertime
 	 */
-	public function saveLog($message)
+	public function getRendertimeString(float $limit = 0)
 	{
-		// Write down the performance values into the log
-		if ($this->enabled) {
-			$duration = microtime(true)-$this->get('start');
-			$this->logger->info(
-				$message,
-				[
-					'module' => 'api',
-					'action' => 'call',
-					'database_read' => round($this->get('database') - $this->get('database_write'), 3),
-					'database_write' => round($this->get('database_write'), 3),
-					'cache_read' => round($this->get('cache'), 3),
-					'cache_write' => round($this->get('cache_write'), 3),
-					'network_io' => round($this->get('network'), 2),
-					'file_io' => round($this->get('file'), 2),
-					'other_io' => round($duration - ($this->get('database')
-							+ $this->get('cache') + $this->get('cache_write')
-							+ $this->get('network') + $this->get('file')), 2),
-					'total' => round($duration, 2)
-				]
-			);
-
-			$o = '';
-			if ($this->rendertime) {
-				if (isset($this->callstack["database"])) {
-					$o .= "\nDatabase Read:\n";
-					foreach ($this->callstack["database"] as $func => $time) {
-						$time = round($time, 3);
-						if ($time > 0) {
-							$o .= $func.": ".$time."\n";
-						}
-					}
+		$output = '';
+
+		if (!$this->enabled || !$this->rendertime) {
+			return $output;
+		}
+
+		if (isset($this->callstack["database"])) {
+			$output .= "\nDatabase Read:\n";
+			foreach ($this->callstack["database"] as $func => $time) {
+				$time = round($time, 3);
+				if ($time > $limit) {
+					$output .= $func . ": " . $time . "\n";
 				}
-				if (isset($this->callstack["database_write"])) {
-					$o .= "\nDatabase Write:\n";
-					foreach ($this->callstack["database_write"] as $func => $time) {
-						$time = round($time, 3);
-						if ($time > 0) {
-							$o .= $func.": ".$time."\n";
-						}
-					}
+			}
+		}
+		if (isset($this->callstack["database_write"])) {
+			$output .= "\nDatabase Write:\n";
+			foreach ($this->callstack["database_write"] as $func => $time) {
+				$time = round($time, 3);
+				if ($time > $limit) {
+					$output .= $func . ": " . $time . "\n";
+				}
+			}
+		}
+		if (isset($this->callstack["cache"])) {
+			$output .= "\nCache Read:\n";
+			foreach ($this->callstack["cache"] as $func => $time) {
+				$time = round($time, 3);
+				if ($time > $limit) {
+					$output .= $func . ": " . $time . "\n";
 				}
-				if (isset($this->callstack["dache"])) {
-					$o .= "\nCache Read:\n";
-					foreach ($this->callstack["dache"] as $func => $time) {
-						$time = round($time, 3);
-						if ($time > 0) {
-							$o .= $func.": ".$time."\n";
-						}
-					}
+			}
+		}
+		if (isset($this->callstack["cache_write"])) {
+			$output .= "\nCache Write:\n";
+			foreach ($this->callstack["cache_write"] as $func => $time) {
+				$time = round($time, 3);
+				if ($time > $limit) {
+					$output .= $func . ": " . $time . "\n";
 				}
-				if (isset($this->callstack["dache_write"])) {
-					$o .= "\nCache Write:\n";
-					foreach ($this->callstack["dache_write"] as $func => $time) {
-						$time = round($time, 3);
-						if ($time > 0) {
-							$o .= $func.": ".$time."\n";
-						}
-					}
+			}
+		}
+		if (isset($this->callstack["network"])) {
+			$output .= "\nNetwork:\n";
+			foreach ($this->callstack["network"] as $func => $time) {
+				$time = round($time, 3);
+				if ($time > $limit) {
+					$output .= $func . ": " . $time . "\n";
 				}
-				if (isset($this->callstack["network"])) {
-					$o .= "\nNetwork:\n";
-					foreach ($this->callstack["network"] as $func => $time) {
-						$time = round($time, 3);
-						if ($time > 0) {
-							$o .= $func.": ".$time."\n";
-						}
-					}
+			}
+		}
+
+		if (isset($this->callstack["rendering"])) {
+			$output .= "\nRendering:\n";
+			foreach ($this->callstack["rendering"] as $func => $time) {
+				$time = round($time, 3);
+				if ($time > $limit) {
+					$output .= $func . ": " . $time . "\n";
 				}
 			}
+		}
+
+		return $output;
+	}
+
+	/**
+	 * Save the current profiling data to a log entry
+	 *
+	 * @param LoggerInterface $logger  The logger to save the current log
+	 * @param string          $message Additional message for the log
+	 */
+	public function saveLog(LoggerInterface $logger, $message = '')
+	{
+		$duration = microtime(true) - $this->get('start');
+		$logger->info(
+			$message,
+			[
+				'action' => 'profiling',
+				'database_read' => round($this->get('database') - $this->get('database_write'), 3),
+				'database_write' => round($this->get('database_write'), 3),
+				'cache_read' => round($this->get('cache'), 3),
+				'cache_write' => round($this->get('cache_write'), 3),
+				'network_io' => round($this->get('network'), 2),
+				'file_io' => round($this->get('file'), 2),
+				'other_io' => round($duration - ($this->get('database')
+						+ $this->get('cache') + $this->get('cache_write')
+						+ $this->get('network') + $this->get('file')), 2),
+				'total' => round($duration, 2)
+			]
+		);
 
-			$this->logger->info(
-				$message . ": " . sprintf(
-					"DB: %s/%s, Cache: %s/%s, Net: %s, I/O: %s, Other: %s, Total: %s".$o,
-					number_format($this->get('database') - $this->get('database_write'), 2),
-					number_format($this->get('database_write'), 2),
-					number_format($this->get('cache'), 2),
-					number_format($this->get('cache_write'), 2),
-					number_format($this->get('network'), 2),
-					number_format($this->get('file'), 2),
-					number_format($duration - ($this->get('database')
-							+ $this->get('cache') + $this->get('cache_write')
-							+ $this->get('network') + $this->get('file')), 2),
-					number_format($duration, 2)
-				)
-			);
+		if ($this->isRendertime()) {
+			$output = $this->getRendertimeString();
+			$logger->info($message . ": " . $output, ['action' => 'profiling']);
 		}
 	}
 
@@ -234,6 +347,11 @@ class Profiler implements ContainerInterface
 		}
 	}
 
+	public function set($timestamp, $id)
+	{
+		$this->performance[$id] = $timestamp;
+	}
+
 	/**
 	 * Returns true if the container can return an entry for the given identifier.
 	 * Returns false otherwise.