Optimization: Initialize debugbar only after the configuration has been loaded

Optimization: Combine some early Grav processors into a single one

CHANGELOG.md

@@ -6,6 +6,8 @@
     * Removed `Gitter` and `Slack` [#2502](https://github.com/getgrav/grav/issues/2502)
     * Optimizations for Plugin/Theme loading
     * Generalized markdown classes so they can be used outside of `Page` scope with a custom `Excerpts` class instance
+    * Optimization: Initialize debugbar only after the configuration has been loaded
+    * Optimization: Combine some early Grav processors into a single one
 1. [](#bugfix)
     * Force question to install demo content in theme update [#2493](https://github.com/getgrav/grav/issues/2493)
     * Fixed GPM errors from blueprints not being logged [#2505](https://github.com/getgrav/grav/issues/2505)

composer.json

@@ -51,7 +51,7 @@
         "dragonmantank/cron-expression": "^1.2",
         "phive/twig-extensions-deferred": "^1.0",
         "willdurand/negotiation": "^2.3",
-        "itsgoingd/clockwork": "^3.1"
+        "itsgoingd/clockwork": "dev-master"
     },
     "require-dev": {
         "codeception/codeception": "^2.4",
@@ -78,6 +78,10 @@
         {
             "type": "vcs",
             "url": "https://github.com/trilbymedia/PHP-Markdown-Documentation-Generator"
+        },
+        {
+            "type": "vcs",
+            "url": "https://github.com/itsgoingd/clockwork"
         }
     ],
     "autoload": {

composer.lock

@@ -4,7 +4,7 @@
         "Read more about it at https://getcomposer.org/doc/01-basic-usage.md#installing-dependencies",
         "This file is @generated automatically"
     ],
-    "content-hash": "1c5e84ccbe601461f02188ff7336c82e",
+    "content-hash": "b33c701d98f2944f5396b14688b6063e",
     "packages": [
         {
             "name": "antoligy/dom-string-iterators",
@@ -660,16 +660,16 @@
         },
         {
             "name": "itsgoingd/clockwork",
-            "version": "v3.1.4",
+            "version": "dev-master",
             "source": {
                 "type": "git",
                 "url": "https://github.com/itsgoingd/clockwork.git",
-                "reference": "529b6f9e2ce487b900213cf1d0694d0aebd5977f"
+                "reference": "68e64591085b0660a72bdf75aab21611b9a98ec9"
             },
             "dist": {
                 "type": "zip",
-                "url": "https://api.github.com/repos/itsgoingd/clockwork/zipball/529b6f9e2ce487b900213cf1d0694d0aebd5977f",
+                "url": "https://api.github.com/repos/itsgoingd/clockwork/zipball/68e64591085b0660a72bdf75aab21611b9a98ec9",
-                "reference": "529b6f9e2ce487b900213cf1d0694d0aebd5977f",
+                "reference": "68e64591085b0660a72bdf75aab21611b9a98ec9",
                 "shasum": ""
             },
             "require": {
@@ -692,7 +692,6 @@
                     "Clockwork\\": "Clockwork/"
                 }
             },
-            "notification-url": "https://packagist.org/downloads/",
             "license": [
                 "MIT"
             ],
@@ -706,15 +705,19 @@
             "description": "php dev tools integrated to your browser",
             "homepage": "https://underground.works/clockwork",
             "keywords": [
-                "Devtools",
                 "debugging",
+                "devtools",
                 "laravel",
                 "logging",
                 "lumen",
                 "profiling",
                 "slim"
             ],
-            "time": "2019-03-21T20:24:39+00:00"
+            "support": {
+                "source": "https://github.com/itsgoingd/clockwork/tree/master",
+                "issues": "https://github.com/itsgoingd/clockwork/issues"
+            },
+            "time": "2019-05-18T20:20:08+00:00"
         },
         {
             "name": "kodus/psr7-server",
@@ -4269,16 +4272,16 @@
         },
         {
             "name": "phpstan/phpstan",
-            "version": "0.11.6",
+            "version": "0.11.7",
             "source": {
                 "type": "git",
                 "url": "https://github.com/phpstan/phpstan.git",
-                "reference": "7af8b9d02b3ab36444dbf4e1b9ca1c1bd5044d81"
+                "reference": "32d87d746c70785f78d239855782d27cde0eb6ee"
             },
             "dist": {
                 "type": "zip",
-                "url": "https://api.github.com/repos/phpstan/phpstan/zipball/7af8b9d02b3ab36444dbf4e1b9ca1c1bd5044d81",
+                "url": "https://api.github.com/repos/phpstan/phpstan/zipball/32d87d746c70785f78d239855782d27cde0eb6ee",
-                "reference": "7af8b9d02b3ab36444dbf4e1b9ca1c1bd5044d81",
+                "reference": "32d87d746c70785f78d239855782d27cde0eb6ee",
                 "shasum": ""
             },
             "require": {
@@ -4287,6 +4290,7 @@
                 "nette/bootstrap": "^2.4 || ^3.0",
                 "nette/di": "^2.4.7 || ^3.0",
                 "nette/robot-loader": "^3.0.1",
+                "nette/schema": "^1.0",
                 "nette/utils": "^2.4.5 || ^3.0",
                 "nikic/php-parser": "^4.0.2",
                 "php": "~7.1",
@@ -4338,26 +4342,26 @@
                 "MIT"
             ],
             "description": "PHPStan - PHP Static Analysis Tool",
-            "time": "2019-05-08T16:33:56+00:00"
+            "time": "2019-05-19T17:36:42+00:00"
         },
         {
             "name": "phpstan/phpstan-deprecation-rules",
-            "version": "0.11",
+            "version": "0.11.1",
             "source": {
                 "type": "git",
                 "url": "https://github.com/phpstan/phpstan-deprecation-rules.git",
-                "reference": "449fee6223220b337760abca4444801ddcc8b38d"
+                "reference": "4991f7599646f97f7a2fc2b74ead018f2104ac8e"
             },
             "dist": {
                 "type": "zip",
-                "url": "https://api.github.com/repos/phpstan/phpstan-deprecation-rules/zipball/449fee6223220b337760abca4444801ddcc8b38d",
+                "url": "https://api.github.com/repos/phpstan/phpstan-deprecation-rules/zipball/4991f7599646f97f7a2fc2b74ead018f2104ac8e",
-                "reference": "449fee6223220b337760abca4444801ddcc8b38d",
+                "reference": "4991f7599646f97f7a2fc2b74ead018f2104ac8e",
                 "shasum": ""
             },
             "require": {
                 "nikic/php-parser": "^4.0",
                 "php": "~7.1",
-                "phpstan/phpstan": "^0.11"
+                "phpstan/phpstan": "^0.11.4"
             },
             "require-dev": {
                 "consistence/coding-standard": "^3.0.1",
@@ -4368,10 +4372,15 @@
                 "phpunit/phpunit": "^7.0",
                 "slevomat/coding-standard": "^4.5.2"
             },
-            "type": "library",
+            "type": "phpstan-extension",
             "extra": {
                 "branch-alias": {
                     "dev-master": "0.11-dev"
+                },
+                "phpstan": {
+                    "includes": [
+                        "rules.neon"
+                    ]
                 }
             },
             "autoload": {
@@ -4384,7 +4393,7 @@
                 "MIT"
             ],
             "description": "PHPStan rules for detecting usage of deprecated classes, methods, properties, constants and traits.",
-            "time": "2018-12-05T18:04:16+00:00"
+            "time": "2019-05-19T19:55:34+00:00"
         },
         {
             "name": "phpunit/php-code-coverage",
@@ -5645,6 +5654,7 @@
     "aliases": [],
     "minimum-stability": "stable",
     "stability-flags": {
+        "itsgoingd/clockwork": 20,
         "victorjonsson/markdowndocs": 20
     },
     "prefer-stable": false,

system/src/Grav/Common/Debugger.php

@@ -36,6 +36,9 @@ use Twig\TemplateWrapper;
 
 class Debugger
 {
+    /** @var static */
+    protected static $instance;
+
     /** @var Grav $grav */
     protected $grav;
 
@@ -73,30 +76,19 @@ class Debugger
      */
     public function __construct()
     {
+        static::$instance = $this;
+
         $this->currentTime = microtime(true);
-        $this->requestTime = $_SERVER['REQUEST_TIME_FLOAT'] ?? GRAV_REQUEST_TIME;
 
         if (!\defined('GRAV_REQUEST_TIME')) {
             \define('GRAV_REQUEST_TIME', $this->currentTime);
         }
 
+        $this->requestTime = $_SERVER['REQUEST_TIME_FLOAT'] ?? GRAV_REQUEST_TIME;
+
         // Enable debugger until $this->init() gets called.
         $this->enabled = true;
 
-        // Clockwork initialization.
-        $this->clockwork = new Clockwork();
-
-        // Debugbar initialization.
-        $this->debugbar = $debugbar = new DebugBar();
-        $debugbar->addCollector(new PhpInfoCollector());
-        $debugbar->addCollector(new MessagesCollector());
-        $debugbar->addCollector(new RequestDataCollector());
-        $debugbar->addCollector(new TimeDataCollector($this->requestTime));
-
-        $debugbar['time']->addMeasure('Server', $debugbar['time']->getRequestStartTime(), GRAV_REQUEST_TIME);
-        $debugbar['time']->addMeasure('Loading', GRAV_REQUEST_TIME, $this->currentTime);
-        $debugbar['time']->addMeasure('Debugger', $this->currentTime, microtime(true));
-
         // Set deprecation collector.
         $this->setErrorHandler();
     }
@@ -127,10 +119,15 @@ class Debugger
         if ($this->enabled) {
             $this->initialized = true;
 
+            // Clockwork initialization.
+            $this->clockwork = $clockwork = new Clockwork();
+
+            // Debugbar initialization.
+            $this->debugbar = $debugbar = new DebugBar();
+
             $plugins_config = (array)$this->config->get('plugins');
             ksort($plugins_config);
 
-            $clockwork = $this->clockwork;
             if ($clockwork) {
                 $log = $this->grav['log'];
                 $clockwork->setStorage(new FileStorage(GRAV_ROOT . '/cache/clockwork'));
@@ -146,14 +143,22 @@ class Debugger
                 if ($this->currentTime !== GRAV_REQUEST_TIME) {
                     $timeLine->addEvent('loading', 'Loading', GRAV_REQUEST_TIME, $this->currentTime);
                 }
+                $timeLine->addEvent('setup', 'Site Setup', $this->currentTime, microtime(true));
             }
 
-            $debugbar = $this->debugbar;
             if ($debugbar) {
+                $debugbar->addCollector(new PhpInfoCollector());
+                $debugbar->addCollector(new MessagesCollector());
+                $debugbar->addCollector(new RequestDataCollector());
+                $debugbar->addCollector(new TimeDataCollector($this->requestTime));
                 $debugbar->addCollector(new MemoryCollector());
                 $debugbar->addCollector(new ExceptionsCollector());
                 $debugbar->addCollector(new ConfigCollector((array)$this->config->get('system'), 'Config'));
                 $debugbar->addCollector(new ConfigCollector($plugins_config, 'Plugins'));
+
+                $debugbar['time']->addMeasure('Server', $debugbar['time']->getRequestStartTime(), GRAV_REQUEST_TIME);
+                $debugbar['time']->addMeasure('Loading', GRAV_REQUEST_TIME, $this->currentTime);
+                $debugbar['time']->addMeasure('Site Setup', $this->currentTime,  microtime(true));
             }
 
             $this->addMessage('Grav v' . GRAV_VERSION);
@@ -349,16 +354,8 @@ class Debugger
      */
     public function startTimer($name, $description = null)
     {
-        if (strpos($name, '_') === 0 || $this->enabled) {
+        if ($this->enabled || strpos($name, '_') === 0) {
-            if ($this->debugbar) {
+            $this->timers[$name] = [$description, microtime(true)];
-                $this->debugbar['time']->startMeasure($name, $description);
-            }
-
-            if ($this->clockwork) {
-                $this->clockwork->startEvent($name, $description ?? $name);
-            }
-
-            $this->timers[] = $name;
         }
 
         return $this;
@@ -373,15 +370,23 @@ class Debugger
      */
     public function stopTimer($name)
     {
-        if (\in_array($name, $this->timers, true) && (strpos($name, '_') === 0 || $this->enabled)) {
+        if (isset($this->timers[$name]) && (strpos($name, '_') === 0 || $this->enabled)) {
+            [$description, $startTime] = $this->timers[$name];
+            $endTime = microtime(true);
+            if ($endTime - $startTime < 0.001) {
+                return $this;
+            }
+
             if ($this->debugbar) {
-                $this->debugbar['time']->stopMeasure($name);
+                $this->debugbar['time']->addMeasure($description, $startTime,  $endTime);
             }
 
             if ($this->clockwork) {
-                $this->clockwork->endEvent($name);
+                $timeLine = $this->clockwork->getTimeline();
+                $timeLine->addEvent($name, $description, $startTime, $endTime);
             }
         }
+        unset($this->timers[$name]);
 
         return $this;
     }

system/src/Grav/Common/Grav.php

@@ -90,8 +90,6 @@ class Grav extends Container
      */
     protected $middleware = [
         'configurationProcessor',
-        'loggerProcessor',
-        'errorsProcessor',
         'debuggerProcessor',
         'initializeProcessor',
         'pluginsProcessor',
@@ -156,7 +154,6 @@ class Grav extends Container
 
         $this->initialized['setup'] = true;
 
-        $this->measureTime('_setup', 'Site Setup', function () use ($environment) {
         // Force environment if passed to the method.
         if ($environment) {
             Setup::$environment = $environment;
@@ -164,7 +161,6 @@ class Grav extends Container
 
         $this['setup'];
         $this['streams'];
-        });
 
         return $this;
     }
@@ -188,12 +184,6 @@ class Grav extends Container
                 'configurationProcessor' => function () {
                     return new ConfigurationProcessor($this);
                 },
-                'loggerProcessor' => function () {
-                    return new LoggerProcessor($this);
-                },
-                'errorsProcessor' => function () {
-                    return new ErrorsProcessor($this);
-                },
                 'debuggerProcessor' => function () {
                     return new DebuggerProcessor($this);
                 },
@@ -478,9 +468,7 @@ class Grav extends Container
             return $container;
         };
 
-        $container->measureTime('_services', 'Services', function () use ($container) {
         $container->registerServices();
-        });
 
         return $container;
     }

system/src/Grav/Common/Processors/ConfigurationProcessor.php

@@ -9,6 +9,9 @@
 
 namespace Grav\Common\Processors;
 
+use Grav\Common\Config\Config;
+use Monolog\Formatter\LineFormatter;
+use Monolog\Handler\SyslogHandler;
 use Psr\Http\Message\ResponseInterface;
 use Psr\Http\Message\ServerRequestInterface;
 use Psr\Http\Server\RequestHandlerInterface;
@@ -20,10 +23,37 @@ class ConfigurationProcessor extends ProcessorBase
 
     public function process(ServerRequestInterface $request, RequestHandlerInterface $handler) : ResponseInterface
     {
-        $this->startTimer();
+        $grav = $this->container;
-        $this->container['config']->init();
+
-        $this->container['plugins']->setup();
+        // Initialize Configuration
-        $this->stopTimer();
+        $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);
     }

system/src/Grav/Common/Processors/ErrorsProcessor.php

@@ -1,29 +0,0 @@
-<?php
-
-/**
- * @package    Grav\Common\Processors
- *
- * @copyright  Copyright (C) 2015 - 2019 Trilby Media, LLC. All rights reserved.
- * @license    MIT License; see LICENSE file for details.
- */
-
-namespace Grav\Common\Processors;
-
-use Psr\Http\Message\ResponseInterface;
-use Psr\Http\Message\ServerRequestInterface;
-use Psr\Http\Server\RequestHandlerInterface;
-
-class ErrorsProcessor extends ProcessorBase
-{
-    public $id = '_errors';
-    public $title = 'Error Handlers Reset';
-
-    public function process(ServerRequestInterface $request, RequestHandlerInterface $handler) : ResponseInterface
-    {
-        $this->startTimer();
-        $this->container['errors']->resetHandlers();
-        $this->stopTimer();
-
-        return $handler->handle($request);
-    }
-}

system/src/Grav/Common/Processors/LoggerProcessor.php

@@ -1,50 +0,0 @@
-<?php
-
-/**
- * @package    Grav\Common\Processors
- *
- * @copyright  Copyright (C) 2015 - 2019 Trilby Media, LLC. All rights reserved.
- * @license    MIT License; see LICENSE file for details.
- */
-
-namespace Grav\Common\Processors;
-
-use Grav\Common\Config\Config;
-use Monolog\Formatter\LineFormatter;
-use Monolog\Handler\SyslogHandler;
-use Psr\Http\Message\ResponseInterface;
-use Psr\Http\Message\ServerRequestInterface;
-use Psr\Http\Server\RequestHandlerInterface;
-
-class LoggerProcessor extends ProcessorBase
-{
-    public $id = '_logger';
-    public $title = 'Logger';
-
-    public function process(ServerRequestInterface $request, RequestHandlerInterface $handler) : ResponseInterface
-    {
-        $this->startTimer();
-
-        $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;
-        }
-        $this->stopTimer();
-
-        return $handler->handle($request);
-    }
-}