src/Util/Profiler.php

   1 <?php
   2 /**
   3  * @copyright Copyright (C) 2020, Friendica
   4  *
   5  * @license GNU AGPL version 3 or any later version
   6  *
   7  * This program is free software: you can redistribute it and/or modify
   8  * it under the terms of the GNU Affero General Public License as
   9  * published by the Free Software Foundation, either version 3 of the
  10  * License, or (at your option) any later version.
  11  *
  12  * This program is distributed in the hope that it will be useful,
  13  * but WITHOUT ANY WARRANTY; without even the implied warranty of
  14  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  15  * GNU Affero General Public License for more details.
  16  *
  17  * You should have received a copy of the GNU Affero General Public License
  18  * along with this program.  If not, see <https://www.gnu.org/licenses/>.
  19  *
  20  */
  21
  22 namespace Friendica\Util;
  23
  24 use Friendica\Core\Config\Cache;
  25 use Friendica\Core\Config\IConfig;
  26 use Friendica\Core\System;
  27 use Psr\Container\ContainerExceptionInterface;
  28 use Psr\Container\ContainerInterface;
  29 use Psr\Container\NotFoundExceptionInterface;
  30 use Psr\Log\LoggerInterface;
  31
  32 /**
  33  * A class to store profiling data
  34  * It can handle different logging data for specific functions or global performance measures
  35  *
  36  * It stores the data as log entries (@see LoggerInterface)
  37  */
  38 class Profiler implements ContainerInterface
  39 {
  40         /**
  41          * @var array The global performance array
  42          */
  43         private $performance;
  44         /**
  45          * @var array The function specific callstack
  46          */
  47         private $callstack;
  48         /**
  49          * @var bool True, if the Profiler is enabled
  50          */
  51         private $enabled;
  52         /**
  53          * @var bool True, if the Profiler should measure the whole rendertime including functions
  54          */
  55         private $rendertime;
  56
  57         /**
  58          * True, if the Profiler should measure the whole rendertime including functions
  59          *
  60          * @return bool
  61          */
  62         public function isRendertime()
  63         {
  64                 return $this->rendertime;
  65         }
  66
  67         /**
  68          * Updates the enabling of the current profiler
  69          *
  70          * @param IConfig $config
  71          */
  72         public function update(IConfig $config)
  73         {
  74                 $this->enabled = $config->get('system', 'profiler');
  75                 $this->rendertime = $config->get('rendertime', 'callstack');
  76         }
  77
  78         /**
  79          * @param Cache $configCache The configuration cache
  80          */
  81         public function __construct(Cache $configCache)
  82         {
  83                 $this->enabled = $configCache->get('system', 'profiler');
  84                 $this->rendertime = $configCache->get('rendertime', 'callstack');
  85                 $this->reset();
  86         }
  87
  88         /**
  89          * Saves a timestamp for a value - f.e. a call
  90          * Necessary for profiling Friendica
  91          *
  92          * @param int    $timestamp the Timestamp
  93          * @param string $value     A value to profile
  94          * @param string $callstack A callstack string, generated if absent
  95          */
  96         public function saveTimestamp($timestamp, $value, $callstack = '')
  97         {
  98                 if (!$this->enabled) {
  99                         return;
 100                 }
 101
 102                 $callstack = $callstack ?: System::callstack(4, 1);
 103
 104                 $duration = floatval(microtime(true) - $timestamp);
 105
 106                 if (!isset($this->performance[$value])) {
 107                         // Prevent ugly E_NOTICE
 108                         $this->performance[$value] = 0;
 109                 }
 110
 111                 $this->performance[$value] += (float) $duration;
 112                 $this->performance['marktime'] += (float) $duration;
 113
 114                 if (!isset($this->callstack[$value][$callstack])) {
 115                         // Prevent ugly E_NOTICE
 116                         $this->callstack[$value][$callstack] = 0;
 117                 }
 118
 119                 $this->callstack[$value][$callstack] += (float) $duration;
 120         }
 121
 122         /**
 123          * Resets the performance and callstack profiling
 124          */
 125         public function reset()
 126         {
 127                 $this->resetPerformance();
 128                 $this->resetCallstack();
 129         }
 130
 131         /**
 132          * Resets the performance profiling data
 133          */
 134         public function resetPerformance()
 135         {
 136                 $this->performance = [];
 137                 $this->performance['start'] = $this->performance['ready'] = microtime(true);
 138                 $this->performance['database'] = 0;
 139                 $this->performance['database_write'] = 0;
 140                 $this->performance['cache'] = 0;
 141                 $this->performance['cache_write'] = 0;
 142                 $this->performance['network'] = 0;
 143                 $this->performance['file'] = 0;
 144                 $this->performance['rendering'] = 0;
 145                 $this->performance['parser'] = 0;
 146                 $this->performance['marktime'] = 0;
 147                 $this->performance['marktime'] = microtime(true);
 148                 $this->performance['frontend'] = 0;
 149                 $this->performance['init'] = 0;
 150                 $this->performance['content'] = 0;
 151         }
 152
 153         /**
 154          * Resets the callstack profiling data
 155          */
 156         public function resetCallstack()
 157         {
 158                 $this->callstack = [];
 159                 $this->callstack['database'] = [];
 160                 $this->callstack['database_write'] = [];
 161                 $this->callstack['cache'] = [];
 162                 $this->callstack['cache_write'] = [];
 163                 $this->callstack['network'] = [];
 164                 $this->callstack['file'] = [];
 165                 $this->callstack['rendering'] = [];
 166                 $this->callstack['parser'] = [];
 167         }
 168
 169         /**
 170          * Returns the rendertime string
 171          * @param float $limit Minimal limit for displaying the execution duration
 172          *
 173          * @return string the rendertime
 174          */
 175         public function getRendertimeString(float $limit = 0)
 176         {
 177                 $output = '';
 178
 179                 if (!$this->enabled || !$this->rendertime) {
 180                         return $output;
 181                 }
 182
 183                 if (isset($this->callstack["database"])) {
 184                         $output .= "\nDatabase Read:\n";
 185                         foreach ($this->callstack["database"] as $func => $time) {
 186                                 $time = round($time, 3);
 187                                 if ($time > $limit) {
 188                                         $output .= $func . ": " . $time . "\n";
 189                                 }
 190                         }
 191                 }
 192                 if (isset($this->callstack["database_write"])) {
 193                         $output .= "\nDatabase Write:\n";
 194                         foreach ($this->callstack["database_write"] as $func => $time) {
 195                                 $time = round($time, 3);
 196                                 if ($time > $limit) {
 197                                         $output .= $func . ": " . $time . "\n";
 198                                 }
 199                         }
 200                 }
 201                 if (isset($this->callstack["cache"])) {
 202                         $output .= "\nCache Read:\n";
 203                         foreach ($this->callstack["cache"] as $func => $time) {
 204                                 $time = round($time, 3);
 205                                 if ($time > $limit) {
 206                                         $output .= $func . ": " . $time . "\n";
 207                                 }
 208                         }
 209                 }
 210                 if (isset($this->callstack["cache_write"])) {
 211                         $output .= "\nCache Write:\n";
 212                         foreach ($this->callstack["cache_write"] as $func => $time) {
 213                                 $time = round($time, 3);
 214                                 if ($time > $limit) {
 215                                         $output .= $func . ": " . $time . "\n";
 216                                 }
 217                         }
 218                 }
 219                 if (isset($this->callstack["network"])) {
 220                         $output .= "\nNetwork:\n";
 221                         foreach ($this->callstack["network"] as $func => $time) {
 222                                 $time = round($time, 3);
 223                                 if ($time > $limit) {
 224                                         $output .= $func . ": " . $time . "\n";
 225                                 }
 226                         }
 227                 }
 228
 229                 return $output;
 230         }
 231
 232         /**
 233          * Save the current profiling data to a log entry
 234          *
 235          * @param LoggerInterface $logger  The logger to save the current log
 236          * @param string          $message Additional message for the log
 237          */
 238         public function saveLog(LoggerInterface $logger, $message = '')
 239         {
 240                 $duration = microtime(true) - $this->get('start');
 241                 $logger->info(
 242                         $message,
 243                         [
 244                                 'action' => 'profiling',
 245                                 'database_read' => round($this->get('database') - $this->get('database_write'), 3),
 246                                 'database_write' => round($this->get('database_write'), 3),
 247                                 'cache_read' => round($this->get('cache'), 3),
 248                                 'cache_write' => round($this->get('cache_write'), 3),
 249                                 'network_io' => round($this->get('network'), 2),
 250                                 'file_io' => round($this->get('file'), 2),
 251                                 'other_io' => round($duration - ($this->get('database')
 252                                                 + $this->get('cache') + $this->get('cache_write')
 253                                                 + $this->get('network') + $this->get('file')), 2),
 254                                 'total' => round($duration, 2)
 255                         ]
 256                 );
 257
 258                 if ($this->isRendertime()) {
 259                         $output = $this->getRendertimeString();
 260                         $logger->info($message . ": " . $output, ['action' => 'profiling']);
 261                 }
 262         }
 263
 264         /**
 265          * Finds an entry of the container by its identifier and returns it.
 266          *
 267          * @param string $id Identifier of the entry to look for.
 268          *
 269          * @throws NotFoundExceptionInterface  No entry was found for **this** identifier.
 270          * @throws ContainerExceptionInterface Error while retrieving the entry.
 271          *
 272          * @return int Entry.
 273          */
 274         public function get($id)
 275         {
 276                 if (!$this->has($id)) {
 277                         return 0;
 278                 } else {
 279                         return $this->performance[$id];
 280                 }
 281         }
 282
 283         public function set($timestamp, $id)
 284         {
 285                 $this->performance[$id] = $timestamp;
 286         }
 287
 288         /**
 289          * Returns true if the container can return an entry for the given identifier.
 290          * Returns false otherwise.
 291          *
 292          * `has($id)` returning true does not mean that `get($id)` will not throw an exception.
 293          * It does however mean that `get($id)` will not throw a `NotFoundExceptionInterface`.
 294          *
 295          * @param string $id Identifier of the entry to look for.
 296          *
 297          * @return bool
 298          */
 299         public function has($id)
 300         {
 301                 return isset($this->performance[$id]);
 302         }
 303 }