]> git.mxchange.org Git - friendica.git/blobdiff - src/Util/Profiler.php
Catch exceptions for Worker::AddContact()
[friendica.git] / src / Util / Profiler.php
index 2d3da3a9c0b99f762a29f9b9bb9e7288a87ab337..24289678c266a41450b751fff3b6132ff8355cd7 100644 (file)
@@ -1,7 +1,29 @@
 <?php
+/**
+ * @copyright Copyright (C) 2010-2022, 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\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;
@@ -11,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
 {
@@ -32,24 +54,99 @@ class Profiler implements ContainerInterface
         */
        private $rendertime;
 
+       private $timestamps = [];
+
        /**
-        * @param bool $enabled           True, if the Profiler is enabled
-        * @param bool $renderTime        True, if the Profiler should measure the whole rendertime including functions
+        * True, if the Profiler should measure the whole rendertime including functions
+        *
+        * @return bool
+        */
+       public function isRendertime()
+       {
+               return $this->rendertime;
+       }
+
+       /**
+        * Updates the enabling of the current profiler
+        *
+        * @param IManageConfigValues $config
         */
-       public function __construct($enabled = false, $renderTime = false)
+       public function update(IManageConfigValues $config)
        {
-               $this->enabled = $enabled;
-               $this->rendertime = $renderTime;
+               $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 string $callstack The callstack of the current profiling data
+        * @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, $callstack = '')
        {
@@ -57,7 +154,9 @@ class Profiler implements ContainerInterface
                        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
@@ -91,6 +190,7 @@ class Profiler implements ContainerInterface
        {
                $this->performance = [];
                $this->performance['start'] = microtime(true);
+               $this->performance['ready'] = 0;
                $this->performance['database'] = 0;
                $this->performance['database_write'] = 0;
                $this->performance['cache'] = 0;
@@ -98,9 +198,13 @@ class Profiler implements ContainerInterface
                $this->performance['network'] = 0;
                $this->performance['file'] = 0;
                $this->performance['rendering'] = 0;
-               $this->performance['parser'] = 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;
        }
 
        /**
@@ -116,90 +220,112 @@ class Profiler implements ContainerInterface
                $this->callstack['network'] = [];
                $this->callstack['file'] = [];
                $this->callstack['rendering'] = [];
-               $this->callstack['parser'] = [];
+               $this->callstack['session'] = [];
        }
 
        /**
-        * Save the current profiling data to a log entry
+        * Returns the rendertime string
+        * @param float $limit Minimal limit for displaying the execution duration
         *
-        * @param LoggerInterface $logger The logger to save the current log
-        * @param string          $message Additional message for the log
+        * @return string the rendertime
         */
-       public function saveLog(LoggerInterface $logger, $message = '')
+       public function getRendertimeString(float $limit = 0)
        {
-               // Write down the performance values into the log
-               if (!$this->enabled) {
-                       return;
-               }
-               $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)
-                       ]
-               );
+               $output = '';
 
-               if (!$this->rendertime) {
-                       return;
+               if (!$this->enabled || !$this->rendertime) {
+                       return $output;
                }
-               
-               $o = '';
+
                if (isset($this->callstack["database"])) {
-                       $o .= "\nDatabase Read:\n";
+                       $output .= "\nDatabase Read:\n";
                        foreach ($this->callstack["database"] as $func => $time) {
                                $time = round($time, 3);
-                               if ($time > 0) {
-                                       $o .= $func . ": " . $time . "\n";
+                               if ($time > $limit) {
+                                       $output .= $func . ": " . $time . "\n";
                                }
                        }
                }
                if (isset($this->callstack["database_write"])) {
-                       $o .= "\nDatabase Write:\n";
+                       $output .= "\nDatabase Write:\n";
                        foreach ($this->callstack["database_write"] as $func => $time) {
                                $time = round($time, 3);
-                               if ($time > 0) {
-                                       $o .= $func . ": " . $time . "\n";
+                               if ($time > $limit) {
+                                       $output .= $func . ": " . $time . "\n";
                                }
                        }
                }
                if (isset($this->callstack["cache"])) {
-                       $o .= "\nCache Read:\n";
+                       $output .= "\nCache Read:\n";
                        foreach ($this->callstack["cache"] as $func => $time) {
                                $time = round($time, 3);
-                               if ($time > 0) {
-                                       $o .= $func . ": " . $time . "\n";
+                               if ($time > $limit) {
+                                       $output .= $func . ": " . $time . "\n";
                                }
                        }
                }
                if (isset($this->callstack["cache_write"])) {
-                       $o .= "\nCache Write:\n";
+                       $output .= "\nCache Write:\n";
                        foreach ($this->callstack["cache_write"] as $func => $time) {
                                $time = round($time, 3);
-                               if ($time > 0) {
-                                       $o .= $func . ": " . $time . "\n";
+                               if ($time > $limit) {
+                                       $output .= $func . ": " . $time . "\n";
                                }
                        }
                }
                if (isset($this->callstack["network"])) {
-                       $o .= "\nNetwork:\n";
+                       $output .= "\nNetwork:\n";
                        foreach ($this->callstack["network"] as $func => $time) {
                                $time = round($time, 3);
-                               if ($time > 0) {
-                                       $o .= $func . ": " . $time . "\n";
+                               if ($time > $limit) {
+                                       $output .= $func . ": " . $time . "\n";
                                }
                        }
                }
-               $logger->info($message . ": " . $o, ['action' => 'profiling']);
+
+               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)
+                       ]
+               );
+
+               if ($this->isRendertime()) {
+                       $output = $this->getRendertimeString();
+                       $logger->info($message . ": " . $output, ['action' => 'profiling']);
+               }
        }
 
        /**
@@ -221,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.