Support for stacked profiler analysis

This commit is contained in:
Michael 2021-07-27 04:57:29 +00:00
parent 3cef3ab107
commit c89533a70b
17 changed files with 763 additions and 611 deletions

View file

@ -59,9 +59,9 @@ class ProfilerLogger implements LoggerInterface
*/
public function emergency($message, array $context = array())
{
$stamp1 = microtime(true);
$this->profiler->startRecording('file');
$this->logger->emergency($message, $context);
$this->profiler->saveTimestamp($stamp1, 'file');
$this->profiler->stopRecording();
}
/**
@ -69,9 +69,9 @@ class ProfilerLogger implements LoggerInterface
*/
public function alert($message, array $context = array())
{
$stamp1 = microtime(true);
$this->profiler->startRecording('file');
$this->logger->alert($message, $context);
$this->profiler->saveTimestamp($stamp1, 'file');
$this->profiler->stopRecording();
}
/**
@ -79,9 +79,9 @@ class ProfilerLogger implements LoggerInterface
*/
public function critical($message, array $context = array())
{
$stamp1 = microtime(true);
$this->profiler->startRecording('file');
$this->logger->critical($message, $context);
$this->profiler->saveTimestamp($stamp1, 'file');
$this->profiler->stopRecording();
}
/**
@ -89,9 +89,9 @@ class ProfilerLogger implements LoggerInterface
*/
public function error($message, array $context = array())
{
$stamp1 = microtime(true);
$this->profiler->startRecording('file');
$this->logger->error($message, $context);
$this->profiler->saveTimestamp($stamp1, 'file');
$this->profiler->stopRecording();
}
/**
@ -99,9 +99,9 @@ class ProfilerLogger implements LoggerInterface
*/
public function warning($message, array $context = array())
{
$stamp1 = microtime(true);
$this->profiler->startRecording('file');
$this->logger->warning($message, $context);
$this->profiler->saveTimestamp($stamp1, 'file');
$this->profiler->stopRecording();
}
/**
@ -109,9 +109,9 @@ class ProfilerLogger implements LoggerInterface
*/
public function notice($message, array $context = array())
{
$stamp1 = microtime(true);
$this->profiler->startRecording('file');
$this->logger->notice($message, $context);
$this->profiler->saveTimestamp($stamp1, 'file');
$this->profiler->stopRecording();
}
/**
@ -119,9 +119,9 @@ class ProfilerLogger implements LoggerInterface
*/
public function info($message, array $context = array())
{
$stamp1 = microtime(true);
$this->profiler->startRecording('file');
$this->logger->info($message, $context);
$this->profiler->saveTimestamp($stamp1, 'file');
$this->profiler->stopRecording();
}
/**
@ -129,9 +129,9 @@ class ProfilerLogger implements LoggerInterface
*/
public function debug($message, array $context = array())
{
$stamp1 = microtime(true);
$this->profiler->startRecording('file');
$this->logger->debug($message, $context);
$this->profiler->saveTimestamp($stamp1, 'file');
$this->profiler->stopRecording();
}
/**
@ -139,8 +139,8 @@ class ProfilerLogger implements LoggerInterface
*/
public function log($level, $message, array $context = array())
{
$stamp1 = microtime(true);
$this->profiler->startRecording('file');
$this->logger->log($level, $message, $context);
$this->profiler->saveTimestamp($stamp1, 'file');
$this->profiler->stopRecording();
}
}

View file

@ -54,6 +54,8 @@ class Profiler implements ContainerInterface
*/
private $rendertime;
private $timestamps = [];
/**
* True, if the Profiler should measure the whole rendertime including functions
*
@ -85,6 +87,48 @@ class Profiler implements ContainerInterface
$this->reset();
}
public function startRecording(string $value)
{
if (!$this->enabled) {
return;
}
$this->timestamps[] = ['value' => $value, 'stamp' => microtime(true), 'credit' => 0];
}
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])) {
// 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;
}
/**
* Saves a timestamp for a value - f.e. a call
* Necessary for profiling Friendica
@ -227,6 +271,15 @@ class Profiler implements ContainerInterface
}
}
}
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;
}