src/Util/Profiler.php

   1 <?php
   2
   3 namespace Friendica\Util;
   4
   5 use Friendica\Core;
   6 use Psr\Container\ContainerExceptionInterface;
   7 use Psr\Container\ContainerInterface;
   8 use Psr\Container\NotFoundExceptionInterface;
   9 use Psr\Log\LoggerInterface;
  10
  11 /**
  12  * A class to store profiling data
  13  * It can handle different logging data for specific functions or global performance measures
  14  *
  15  * It stores the data as log entries (@see LoggerInterface )
  16  */
  17 class Profiler implements ContainerInterface
  18 {
  19         /**
  20          * @var array The global performance array
  21          */
  22         private $performance;
  23         /**
  24          * @var array The function specific callstack
  25          */
  26         private $callstack;
  27         /**
  28          * @var bool True, if the Profiler is enabled
  29          */
  30         private $enabled;
  31         /**
  32          * @var bool True, if the Profiler should measure the whole rendertime including functions
  33          */
  34         private $rendertime;
  35
  36         /**
  37          * @var LoggerInterface The profiler logger
  38          */
  39         private $logger;
  40
  41         /**
  42          * @param LoggerInterface $logger The profiler logger
  43          * @param bool $enabled           True, if the Profiler is enabled
  44          * @param bool $renderTime        True, if the Profiler should measure the whole rendertime including functions
  45          */
  46         public function __construct(LoggerInterface $logger, $enabled = false, $renderTime = false)
  47         {
  48                 $this->enabled = $enabled;
  49                 $this->rendertime = $renderTime;
  50                 $this->logger = $logger;
  51                 $this->performance = [];
  52                 $this->callstack   = [];
  53         }
  54
  55         /**
  56          * Saves a timestamp for a value - f.e. a call
  57          * Necessary for profiling Friendica
  58          *
  59          * @param int $timestamp the Timestamp
  60          * @param string $value A value to profile
  61          */
  62         public function saveTimestamp($timestamp, $value)
  63         {
  64                 if (!$this->enabled) {
  65                         return;
  66                 }
  67
  68                 $duration = (float) (microtime(true) - $timestamp);
  69
  70                 if (!isset($this->performance[$value])) {
  71                         // Prevent ugly E_NOTICE
  72                         $this->performance[$value] = 0;
  73                 }
  74
  75                 $this->performance[$value] += (float) $duration;
  76                 $this->performance['marktime'] += (float) $duration;
  77
  78                 $callstack = Core\System::callstack();
  79
  80                 if (!isset($this->callstack[$value][$callstack])) {
  81                         // Prevent ugly E_NOTICE
  82                         $this->callstack[$value][$callstack] = 0;
  83                 }
  84
  85                 $this->callstack[$value][$callstack] += (float) $duration;
  86         }
  87
  88         /**
  89          * Resets the performance and callstack profiling
  90          *
  91          * @param bool $performance If true, reset the performance (Default true)
  92          * @param bool $callstack   If true, reset the callstack (Default true)
  93          */
  94         public function reset($performance = true, $callstack = true)
  95         {
  96                 if ($performance) {
  97                         $this->performance = [];
  98                         $this->performance['start'] = microtime(true);
  99                         $this->performance['database'] = 0;
 100                         $this->performance['database_write'] = 0;
 101                         $this->performance['cache'] = 0;
 102                         $this->performance['cache_write'] = 0;
 103                         $this->performance['network'] = 0;
 104                         $this->performance['file'] = 0;
 105                         $this->performance['rendering'] = 0;
 106                         $this->performance['parser'] = 0;
 107                         $this->performance['marktime'] = 0;
 108                         $this->performance['markstart'] = microtime(true);
 109                 }
 110
 111                 if ($callstack) {
 112                         $this->callstack['database'] = [];
 113                         $this->callstack['database_write'] = [];
 114                         $this->callstack['cache'] = [];
 115                         $this->callstack['cache_write'] = [];
 116                         $this->callstack['network'] = [];
 117                         $this->callstack['file'] = [];
 118                         $this->callstack['rendering'] = [];
 119                         $this->callstack['parser'] = [];
 120                 }
 121         }
 122
 123         /**
 124          * Save the current profiling data to a log entry
 125          *
 126          * @param string $message Additional message for the log
 127          */
 128         public function saveLog($message)
 129         {
 130                 // Write down the performance values into the log
 131                 if ($this->enabled) {
 132                         $duration = microtime(true)-$this->get('start');
 133                         $this->logger->info(
 134                                 $message,
 135                                 [
 136                                         'module' => 'api',
 137                                         'action' => 'call',
 138                                         'database_read' => round($this->get('database') - $this->get('database_write'), 3),
 139                                         'database_write' => round($this->get('database_write'), 3),
 140                                         'cache_read' => round($this->get('cache'), 3),
 141                                         'cache_write' => round($this->get('cache_write'), 3),
 142                                         'network_io' => round($this->get('network'), 2),
 143                                         'file_io' => round($this->get('file'), 2),
 144                                         'other_io' => round($duration - ($this->get('database')
 145                                                         + $this->get('cache') + $this->get('cache_write')
 146                                                         + $this->get('network') + $this->get('file')), 2),
 147                                         'total' => round($duration, 2)
 148                                 ]
 149                         );
 150
 151                         $o = '';
 152                         if ($this->rendertime) {
 153                                 if (isset($this->callstack["database"])) {
 154                                         $o .= "\nDatabase Read:\n";
 155                                         foreach ($this->callstack["database"] as $func => $time) {
 156                                                 $time = round($time, 3);
 157                                                 if ($time > 0) {
 158                                                         $o .= $func.": ".$time."\n";
 159                                                 }
 160                                         }
 161                                 }
 162                                 if (isset($this->callstack["database_write"])) {
 163                                         $o .= "\nDatabase Write:\n";
 164                                         foreach ($this->callstack["database_write"] as $func => $time) {
 165                                                 $time = round($time, 3);
 166                                                 if ($time > 0) {
 167                                                         $o .= $func.": ".$time."\n";
 168                                                 }
 169                                         }
 170                                 }
 171                                 if (isset($this->callstack["dache"])) {
 172                                         $o .= "\nCache Read:\n";
 173                                         foreach ($this->callstack["dache"] as $func => $time) {
 174                                                 $time = round($time, 3);
 175                                                 if ($time > 0) {
 176                                                         $o .= $func.": ".$time."\n";
 177                                                 }
 178                                         }
 179                                 }
 180                                 if (isset($this->callstack["dache_write"])) {
 181                                         $o .= "\nCache Write:\n";
 182                                         foreach ($this->callstack["dache_write"] as $func => $time) {
 183                                                 $time = round($time, 3);
 184                                                 if ($time > 0) {
 185                                                         $o .= $func.": ".$time."\n";
 186                                                 }
 187                                         }
 188                                 }
 189                                 if (isset($this->callstack["network"])) {
 190                                         $o .= "\nNetwork:\n";
 191                                         foreach ($this->callstack["network"] as $func => $time) {
 192                                                 $time = round($time, 3);
 193                                                 if ($time > 0) {
 194                                                         $o .= $func.": ".$time."\n";
 195                                                 }
 196                                         }
 197                                 }
 198                         }
 199
 200                         $this->logger->info(
 201                                 $message . ": " . sprintf(
 202                                         "DB: %s/%s, Cache: %s/%s, Net: %s, I/O: %s, Other: %s, Total: %s".$o,
 203                                         number_format($this->get('database') - $this->get('database_write'), 2),
 204                                         number_format($this->get('database_write'), 2),
 205                                         number_format($this->get('cache'), 2),
 206                                         number_format($this->get('cache_write'), 2),
 207                                         number_format($this->get('network'), 2),
 208                                         number_format($this->get('file'), 2),
 209                                         number_format($duration - ($this->get('database')
 210                                                         + $this->get('cache') + $this->get('cache_write')
 211                                                         + $this->get('network') + $this->get('file')), 2),
 212                                         number_format($duration, 2)
 213                                 )
 214                         );
 215                 }
 216         }
 217
 218         /**
 219          * Finds an entry of the container by its identifier and returns it.
 220          *
 221          * @param string $id Identifier of the entry to look for.
 222          *
 223          * @throws NotFoundExceptionInterface  No entry was found for **this** identifier.
 224          * @throws ContainerExceptionInterface Error while retrieving the entry.
 225          *
 226          * @return int Entry.
 227          */
 228         public function get($id)
 229         {
 230                 if (!$this->has($id)) {
 231                         return 0;
 232                 } else {
 233                         return $this->performance[$id];
 234                 }
 235         }
 236
 237         /**
 238          * Returns true if the container can return an entry for the given identifier.
 239          * Returns false otherwise.
 240          *
 241          * `has($id)` returning true does not mean that `get($id)` will not throw an exception.
 242          * It does however mean that `get($id)` will not throw a `NotFoundExceptionInterface`.
 243          *
 244          * @param string $id Identifier of the entry to look for.
 245          *
 246          * @return bool
 247          */
 248         public function has($id)
 249         {
 250                 return isset($this->performance[$id]);
 251         }
 252 }