friendica/src/Util/Profiler.php

273 lines
6.9 KiB
PHP
Raw Normal View History

2019-02-16 23:11:30 +01:00
<?php
namespace Friendica\Util;
use Psr\Container\ContainerExceptionInterface;
use Psr\Container\ContainerInterface;
use Psr\Container\NotFoundExceptionInterface;
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 )
*/
class Profiler implements ContainerInterface
{
/**
* @var array The global performance array
*/
private $performance;
/**
* @var array The function specific callstack
*/
private $callstack;
/**
* @var bool True, if the Profiler is enabled
*/
private $enabled;
/**
* @var bool True, if the Profiler should measure the whole rendertime including functions
*/
private $rendertime;
2019-02-20 17:20:17 +01:00
/**
* 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 bool $enabled
* @param bool $renderTime
*/
public function update($enabled = false, $renderTime = false)
{
$this->enabled = $enabled;
$this->rendertime = $renderTime;
}
2019-02-16 23:11:30 +01:00
/**
* @param bool $enabled True, if the Profiler is enabled
* @param bool $renderTime True, if the Profiler should measure the whole rendertime including functions
*/
public function __construct($enabled = false, $renderTime = false)
2019-02-16 23:11:30 +01:00
{
$this->enabled = $enabled;
$this->rendertime = $renderTime;
2019-02-17 00:03:38 +01:00
$this->reset();
2019-02-16 23:11:30 +01:00
}
/**
* 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
2019-02-16 23:11:30 +01:00
*/
public function saveTimestamp($timestamp, $value, $callstack = '')
2019-02-16 23:11:30 +01:00
{
if (!$this->enabled) {
return;
}
$duration = (float) (microtime(true) - $timestamp);
if (!isset($this->performance[$value])) {
// Prevent ugly E_NOTICE
$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;
}
/**
* Resets the performance and callstack profiling
*/
2019-02-17 10:34:48 +01:00
public function reset()
2019-02-16 23:11:30 +01:00
{
2019-02-17 10:34:48 +01:00
$this->resetPerformance();
$this->resetCallstack();
2019-02-16 23:11:30 +01:00
}
2019-02-17 01:18:21 +01:00
/**
* Resets the performance profiling data
*/
public function resetPerformance()
{
$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['marktime'] = microtime(true);
}
/**
* 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['parser'] = [];
}
2019-02-16 23:11:30 +01:00
/**
2019-02-20 17:12:40 +01:00
* Returns the rendertime string
2019-02-16 23:11:30 +01:00
*
2019-02-20 17:12:40 +01:00
* @return string the rendertime
2019-02-16 23:11:30 +01:00
*/
2019-02-20 17:12:40 +01:00
public function getRendertimeString()
2019-02-16 23:11:30 +01:00
{
2019-02-20 17:12:40 +01:00
$output = '';
2019-02-17 01:18:21 +01:00
2019-02-20 17:12:40 +01:00
if (!$this->enabled || !$this->rendertime) {
return $output;
2019-02-17 01:18:21 +01:00
}
2019-02-20 17:12:40 +01:00
2019-02-17 01:18:21 +01:00
if (isset($this->callstack["database"])) {
2019-02-20 17:12:40 +01:00
$output .= "\nDatabase Read:\n";
2019-02-17 01:18:21 +01:00
foreach ($this->callstack["database"] as $func => $time) {
$time = round($time, 3);
if ($time > 0) {
2019-02-20 17:12:40 +01:00
$output .= $func . ": " . $time . "\n";
2019-02-16 23:11:30 +01:00
}
2019-02-17 01:18:21 +01:00
}
}
if (isset($this->callstack["database_write"])) {
2019-02-20 17:12:40 +01:00
$output .= "\nDatabase Write:\n";
2019-02-17 01:18:21 +01:00
foreach ($this->callstack["database_write"] as $func => $time) {
$time = round($time, 3);
if ($time > 0) {
2019-02-20 17:12:40 +01:00
$output .= $func . ": " . $time . "\n";
2019-02-16 23:11:30 +01:00
}
2019-02-17 01:18:21 +01:00
}
}
if (isset($this->callstack["cache"])) {
2019-02-20 17:12:40 +01:00
$output .= "\nCache Read:\n";
2019-02-17 01:18:21 +01:00
foreach ($this->callstack["cache"] as $func => $time) {
$time = round($time, 3);
if ($time > 0) {
2019-02-20 17:12:40 +01:00
$output .= $func . ": " . $time . "\n";
2019-02-16 23:11:30 +01:00
}
2019-02-17 01:18:21 +01:00
}
}
if (isset($this->callstack["cache_write"])) {
2019-02-20 17:12:40 +01:00
$output .= "\nCache Write:\n";
2019-02-17 01:18:21 +01:00
foreach ($this->callstack["cache_write"] as $func => $time) {
$time = round($time, 3);
if ($time > 0) {
2019-02-20 17:12:40 +01:00
$output .= $func . ": " . $time . "\n";
2019-02-16 23:11:30 +01:00
}
2019-02-17 01:18:21 +01:00
}
}
if (isset($this->callstack["network"])) {
2019-02-20 17:12:40 +01:00
$output .= "\nNetwork:\n";
2019-02-17 01:18:21 +01:00
foreach ($this->callstack["network"] as $func => $time) {
$time = round($time, 3);
if ($time > 0) {
2019-02-20 17:12:40 +01:00
$output .= $func . ": " . $time . "\n";
2019-02-16 23:11:30 +01:00
}
}
}
2019-02-20 17:12:40 +01:00
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)
]
);
2019-02-20 17:20:17 +01:00
if ($this->isRendertime()) {
$output = $this->getRendertimeString();
$logger->info($message . ": " . $output, ['action' => 'profiling']);
}
2019-02-16 23:11:30 +01:00
}
/**
* Finds an entry of the container by its identifier and returns it.
*
* @param string $id Identifier of the entry to look for.
*
* @throws NotFoundExceptionInterface No entry was found for **this** identifier.
* @throws ContainerExceptionInterface Error while retrieving the entry.
*
* @return int Entry.
*/
public function get($id)
{
if (!$this->has($id)) {
return 0;
} else {
return $this->performance[$id];
}
}
/**
* Returns true if the container can return an entry for the given identifier.
* Returns false otherwise.
*
* `has($id)` returning true does not mean that `get($id)` will not throw an exception.
* It does however mean that `get($id)` will not throw a `NotFoundExceptionInterface`.
*
* @param string $id Identifier of the entry to look for.
*
* @return bool
*/
public function has($id)
{
return isset($this->performance[$id]);
}
}