From 5e2545c606372cbc35b449df9100a58a347ee8a1 Mon Sep 17 00:00:00 2001 From: Matias Griese Date: Mon, 27 May 2019 13:36:19 +0300 Subject: [PATCH] Improve debugger to have less impact when it's not enabled --- system/src/Grav/Common/Debugger.php | 64 ++++--- system/src/Grav/Common/Grav.php | 12 -- .../Processors/ConfigurationProcessor.php | 60 ------ .../Common/Processors/DebuggerProcessor.php | 138 -------------- .../Common/Processors/InitializeProcessor.php | 175 +++++++++++++++++- 5 files changed, 210 insertions(+), 239 deletions(-) delete mode 100644 system/src/Grav/Common/Processors/ConfigurationProcessor.php delete mode 100644 system/src/Grav/Common/Processors/DebuggerProcessor.php diff --git a/system/src/Grav/Common/Debugger.php b/system/src/Grav/Common/Debugger.php index 4f22cc0ff..f05d3d2e6 100644 --- a/system/src/Grav/Common/Debugger.php +++ b/system/src/Grav/Common/Debugger.php @@ -55,7 +55,7 @@ class Debugger protected $clockwork; /** @var bool */ - protected $enabled; + protected $enabled = false; protected $initialized = false; @@ -86,9 +86,6 @@ class Debugger $this->requestTime = $_SERVER['REQUEST_TIME_FLOAT'] ?? GRAV_REQUEST_TIME; - // Enable debugger until $this->init() gets called. - $this->enabled = true; - // Set deprecation collector. $this->setErrorHandler(); } @@ -168,6 +165,7 @@ class Debugger } $this->addMessage('Grav v' . GRAV_VERSION); + $this->config->debug(); if ($clockwork) { $clockwork->info('System Configuration', $this->config->get('system')); @@ -183,6 +181,8 @@ class Debugger public function finalize(): void { if ($this->clockwork && $this->enabled) { + $this->addMeasures(); + $deprecations = $this->getDeprecations(); $count = count($deprecations); if (!$count) { @@ -190,7 +190,7 @@ class Debugger } /** @var UserData $userData */ - $userData = $this->clockwork->userData("Deprecated ({$count})"); + $userData = $this->clockwork->userData('Deprecated'); $userData->counters([ 'Deprecated' => count($deprecations) ]); @@ -208,6 +208,34 @@ class Debugger } } + protected function addMeasures() + { + if (!$this->enabled) { + return; + } + + $nowTime = microtime(true); + $clkTimeLine = $this->clockwork ? $this->clockwork->getTimeline() : null; + $debTimeLine = $this->debugbar ? $this->debugbar['time'] : null; + foreach ($this->timers as $name => $data) { + $description = $data[0]; + $startTime = $data[1]; + $endTime = $data[2] ?? $nowTime; + if ($endTime - $startTime < 0.001) { + continue; + } + + if ($clkTimeLine) { + $clkTimeLine->addEvent($name, $description, $startTime, $endTime); + } + + if ($debTimeLine) { + $debTimeLine->addMeasure($description, $startTime, $endTime); + } + } + $this->timers = []; + } + /** * Set/get the enabled state of the debugger * @@ -301,6 +329,8 @@ class Debugger if ($this->debugbar) { return $this->debugbar->getCollector($collector); } + + return null; } /** @@ -317,6 +347,7 @@ class Debugger return $this; } + $this->addMeasures(); $this->addDeprecations(); echo $this->renderer->render(); @@ -333,6 +364,7 @@ class Debugger public function sendDataInHeaders() { if ($this->enabled && $this->debugbar) { + $this->addMeasures(); $this->addDeprecations(); $this->debugbar->sendDataInHeaders(); } @@ -351,6 +383,7 @@ class Debugger return null; } + $this->addMeasures(); $this->addDeprecations(); $this->timers = []; @@ -367,9 +400,7 @@ class Debugger */ public function startTimer($name, $description = null) { - if ($this->enabled || strpos($name, '_') === 0) { - $this->timers[$name] = [$description, microtime(true)]; - } + $this->timers[$name] = [$description, microtime(true)]; return $this; } @@ -383,23 +414,10 @@ class Debugger */ public function stopTimer($name) { - if (isset($this->timers[$name]) && (strpos($name, '_') === 0 || $this->enabled)) { - [$description, $startTime] = $this->timers[$name]; + if (isset($this->timers[$name])) { $endTime = microtime(true); - if ($endTime - $startTime < 0.001) { - return $this; - } - - if ($this->debugbar) { - $this->debugbar['time']->addMeasure($description, $startTime, $endTime); - } - - if ($this->clockwork) { - $timeLine = $this->clockwork->getTimeline(); - $timeLine->addEvent($name, $description, $startTime, $endTime); - } + $this->timers[$name][] = $endTime; } - unset($this->timers[$name]); return $this; } diff --git a/system/src/Grav/Common/Grav.php b/system/src/Grav/Common/Grav.php index 5dba5ff9e..a3fd65e75 100644 --- a/system/src/Grav/Common/Grav.php +++ b/system/src/Grav/Common/Grav.php @@ -16,12 +16,8 @@ use Grav\Common\Page\Medium\ImageMedium; use Grav\Common\Page\Medium\Medium; use Grav\Common\Processors\AssetsProcessor; use Grav\Common\Processors\BackupsProcessor; -use Grav\Common\Processors\ConfigurationProcessor; use Grav\Common\Processors\DebuggerAssetsProcessor; -use Grav\Common\Processors\DebuggerProcessor; -use Grav\Common\Processors\ErrorsProcessor; use Grav\Common\Processors\InitializeProcessor; -use Grav\Common\Processors\LoggerProcessor; use Grav\Common\Processors\PagesProcessor; use Grav\Common\Processors\PluginsProcessor; use Grav\Common\Processors\RenderProcessor; @@ -89,8 +85,6 @@ class Grav extends Container * @var array All middleware processors that are processed in $this->process() */ protected $middleware = [ - 'configurationProcessor', - 'debuggerProcessor', 'initializeProcessor', 'pluginsProcessor', 'themesProcessor', @@ -181,12 +175,6 @@ class Grav extends Container $container = new Container( [ - 'configurationProcessor' => function () { - return new ConfigurationProcessor($this); - }, - 'debuggerProcessor' => function () { - return new DebuggerProcessor($this); - }, 'initializeProcessor' => function () { return new InitializeProcessor($this); }, diff --git a/system/src/Grav/Common/Processors/ConfigurationProcessor.php b/system/src/Grav/Common/Processors/ConfigurationProcessor.php deleted file mode 100644 index 365f7e007..000000000 --- a/system/src/Grav/Common/Processors/ConfigurationProcessor.php +++ /dev/null @@ -1,60 +0,0 @@ -container; - - // Initialize Configuration - $this->startTimer('_config', 'Configuration'); - /** @var Config $config */ - $config = $grav['config']; - $config->init(); - $grav['plugins']->setup(); - $this->stopTimer('_config'); - - // Initialize Logging - $this->startTimer('_logger', 'Logger'); - switch ($config->get('system.log.handler', 'file')) { - case 'syslog': - $log = $grav['log']; - $log->popHandler(); - - $facility = $config->get('system.log.syslog.facility', 'local6'); - $logHandler = new SyslogHandler('grav', $facility); - $formatter = new LineFormatter("%channel%.%level_name%: %message% %extra%"); - $logHandler->setFormatter($formatter); - - $log->pushHandler($logHandler); - break; - } - $this->stopTimer('_logger'); - - // Initialize Error Handlers - $this->startTimer('_errors', 'Error Handlers Reset'); - $this->container['errors']->resetHandlers(); - $this->stopTimer('_errors'); - - return $handler->handle($request); - } -} diff --git a/system/src/Grav/Common/Processors/DebuggerProcessor.php b/system/src/Grav/Common/Processors/DebuggerProcessor.php deleted file mode 100644 index e58772566..000000000 --- a/system/src/Grav/Common/Processors/DebuggerProcessor.php +++ /dev/null @@ -1,138 +0,0 @@ -startTimer(); - - /** @var Debugger $debugger */ - $debugger = $this->container['debugger']->init(); - - $clockwork = $debugger->getClockwork(); - if ($clockwork) { - $server = $request->getServerParams(); - $baseUri = parse_url(dirname($server['PHP_SELF']), PHP_URL_PATH); - if ($baseUri === '/') { - $baseUri = ''; - } - $requestTime = $_SERVER['REQUEST_TIME_FLOAT'] ?? GRAV_REQUEST_TIME; - - $request = $request - ->withAttribute('base_uri', $baseUri) - ->withAttribute('request_time', $requestTime); - - // Handle clockwork API calls. - $uri = $request->getUri(); - if (mb_strpos($uri->getPath(), $baseUri . '/__clockwork/') === 0) { - return $this->retrieveRequest($request, $clockwork); - } - - $this->container['clockwork'] = $clockwork; - } - - $this->stopTimer(); - - $response = $handler->handle($request); - - if ($clockwork) { - $debugger->finalize(); - - return $this->logRequest($request, $response, $clockwork); - } - - return $response; - } - - protected function logRequest(ServerRequestInterface $request, ResponseInterface $response, Clockwork $clockwork) - { - $clockwork->getTimeline()->finalize($request->getAttribute('request_time')); - $clockwork->addDataSource(new PsrMessageDataSource($request, $response)); - - $clockwork->resolveRequest(); - $clockwork->storeRequest(); - - $clockworkRequest = $clockwork->getRequest(); - - $response = $response - ->withHeader('X-Clockwork-Id', $clockworkRequest->id) - ->withHeader('X-Clockwork-Version', $clockwork::VERSION); - - $basePath = $request->getAttribute('base_uri'); - if ($basePath) { - $response = $response->withHeader('X-Clockwork-Path', $basePath . '/__clockwork/'); - } - - return $response->withHeader('Server-Timing', ServerTiming::fromRequest($clockworkRequest)->value()); - } - - protected function retrieveRequest(RequestInterface $request, Clockwork $clockwork): Response - { - $headers = [ - 'Content-Type' => 'application/json', - 'Grav-Internal-SkipShutdown' => 1 - ]; - - $path = $request->getUri()->getPath(); - $clockworkDataUri = '#/__clockwork(?:/(?[0-9-]+))?(?:/(?(?:previous|next)))?(?:/(?\d+))?#'; - if (preg_match($clockworkDataUri, $path, $matches) === false) { - $response = ['message' => 'Bad Input']; - - return new Response(400, $headers, json_encode($response)); - } - - $id = $matches['id'] ?? null; - $direction = $matches['direction'] ?? null; - $count = $matches['count'] ?? null; - - $storage = $clockwork->getStorage(); - - if ($direction === 'previous') { - $data = $storage->previous($id, $count); - } elseif ($direction === 'next') { - $data = $storage->next($id, $count); - } elseif ($id === 'latest') { - $data = $storage->latest(); - } else { - $data = $storage->find($id); - } - - if (preg_match('#(?[0-9-]+|latest)/extended#', $path)) { - $clockwork->extendRequest($data); - } - - if (!$data) { - $response = ['message' => 'Not Found']; - - return new Response(404, $headers, json_encode($response)); - } - - $data = is_array($data) ? array_map(function ($item) { return $item->toArray(); }, $data) : $data->toArray(); - - return new Response(200, $headers, json_encode($data)); - } -} diff --git a/system/src/Grav/Common/Processors/InitializeProcessor.php b/system/src/Grav/Common/Processors/InitializeProcessor.php index fe2869ce7..6d23c67b0 100644 --- a/system/src/Grav/Common/Processors/InitializeProcessor.php +++ b/system/src/Grav/Common/Processors/InitializeProcessor.php @@ -9,26 +9,192 @@ namespace Grav\Common\Processors; +use Clockwork\Clockwork; +use Clockwork\DataSource\PsrMessageDataSource; +use Clockwork\Helpers\ServerTiming; use Grav\Common\Config\Config; +use Grav\Common\Debugger; use Grav\Common\Uri; use Grav\Common\Utils; +use Grav\Framework\Psr7\Response; use Grav\Framework\Session\Exceptions\SessionException; +use Monolog\Formatter\LineFormatter; +use Monolog\Handler\SyslogHandler; +use Psr\Http\Message\RequestInterface; use Psr\Http\Message\ResponseInterface; use Psr\Http\Message\ServerRequestInterface; use Psr\Http\Server\RequestHandlerInterface; class InitializeProcessor extends ProcessorBase { - public $id = 'init'; + public $id = '_init'; public $title = 'Initialize'; public function process(ServerRequestInterface $request, RequestHandlerInterface $handler) : ResponseInterface { - $this->startTimer(); + $this->startTimer('_config', 'Configuration'); + $this->initializeConfig(); + $this->stopTimer('_config'); + $this->startTimer('_logger', 'Logger'); + $this->initializeLogger(); + $this->stopTimer('_logger'); + + $this->startTimer('_errors', 'Error Handlers Reset'); + $this->initializeErrors(); + $this->stopTimer('_errors'); + + $this->startTimer('_debugger', 'Init Debugger'); + /** @var Debugger $debugger */ + $debugger = $this->container['debugger']->init(); + $clockwork = $debugger->getClockwork(); + if ($clockwork) { + $server = $request->getServerParams(); + $baseUri = parse_url(dirname($server['PHP_SELF']), PHP_URL_PATH); + if ($baseUri === '/') { + $baseUri = ''; + } + $requestTime = $_SERVER['REQUEST_TIME_FLOAT'] ?? GRAV_REQUEST_TIME; + + $request = $request + ->withAttribute('base_uri', $baseUri) + ->withAttribute('request_time', $requestTime); + + // Handle clockwork API calls. + $uri = $request->getUri(); + if (mb_strpos($uri->getPath(), $baseUri . '/__clockwork/') === 0) { + return $this->debuggerRequest($request, $clockwork); + } + + $this->container['clockwork'] = $clockwork; + } + $this->stopTimer('_debugger'); + + + $this->startTimer('_init', 'Initialize'); + $this->initialize(); + $this->stopTimer('_init'); + + $response = $handler->handle($request); + + if ($clockwork) { + $debugger->finalize(); + + return $this->logRequest($request, $response, $clockwork); + } + + return $response; + } + + protected function logRequest(ServerRequestInterface $request, ResponseInterface $response, Clockwork $clockwork) + { + $clockwork->getTimeline()->finalize($request->getAttribute('request_time')); + $clockwork->addDataSource(new PsrMessageDataSource($request, $response)); + + $clockwork->resolveRequest(); + $clockwork->storeRequest(); + + $clockworkRequest = $clockwork->getRequest(); + + $response = $response + ->withHeader('X-Clockwork-Id', $clockworkRequest->id) + ->withHeader('X-Clockwork-Version', $clockwork::VERSION); + + $basePath = $request->getAttribute('base_uri'); + if ($basePath) { + $response = $response->withHeader('X-Clockwork-Path', $basePath . '/__clockwork/'); + } + + return $response->withHeader('Server-Timing', ServerTiming::fromRequest($clockworkRequest)->value()); + } + + protected function debuggerRequest(RequestInterface $request, Clockwork $clockwork): Response + { + $headers = [ + 'Content-Type' => 'application/json', + 'Grav-Internal-SkipShutdown' => 1 + ]; + + $path = $request->getUri()->getPath(); + $clockworkDataUri = '#/__clockwork(?:/(?[0-9-]+))?(?:/(?(?:previous|next)))?(?:/(?\d+))?#'; + if (preg_match($clockworkDataUri, $path, $matches) === false) { + $response = ['message' => 'Bad Input']; + + return new Response(400, $headers, json_encode($response)); + } + + $id = $matches['id'] ?? null; + $direction = $matches['direction'] ?? null; + $count = $matches['count'] ?? null; + + $storage = $clockwork->getStorage(); + + if ($direction === 'previous') { + $data = $storage->previous($id, $count); + } elseif ($direction === 'next') { + $data = $storage->next($id, $count); + } elseif ($id === 'latest') { + $data = $storage->latest(); + } else { + $data = $storage->find($id); + } + + if (preg_match('#(?[0-9-]+|latest)/extended#', $path)) { + $clockwork->extendRequest($data); + } + + if (!$data) { + $response = ['message' => 'Not Found']; + + return new Response(404, $headers, json_encode($response)); + } + + $data = is_array($data) ? array_map(function ($item) { return $item->toArray(); }, $data) : $data->toArray(); + + return new Response(200, $headers, json_encode($data)); + } + + protected function initializeConfig() + { + // Initialize Configuration + $grav = $this->container; + /** @var Config $config */ + $config = $grav['config']; + $config->init(); + $grav['plugins']->setup(); + } + + protected function initializeLogger() + { + // Initialize Logging + $grav = $this->container; + /** @var Config $config */ + $config = $grav['config']; + switch ($config->get('system.log.handler', 'file')) { + case 'syslog': + $log = $grav['log']; + $log->popHandler(); + + $facility = $config->get('system.log.syslog.facility', 'local6'); + $logHandler = new SyslogHandler('grav', $facility); + $formatter = new LineFormatter("%channel%.%level_name%: %message% %extra%"); + $logHandler->setFormatter($formatter); + + $log->pushHandler($logHandler); + break; + } + } + + protected function initializeErrors() + { + // Initialize Error Handlers + $this->container['errors']->resetHandlers(); + } + + protected function initialize() + { /** @var Config $config */ $config = $this->container['config']; - $config->debug(); // Use output buffering to prevent headers from being sent too early. ob_start(); @@ -73,8 +239,5 @@ class InitializeProcessor extends ProcessorBase } $this->container->setLocale(); - $this->stopTimer(); - - return $handler->handle($request); } }