Merge pull request #8241 from creative-commoners/pulls/4.3/separate-logging

Separate core error logging from standard LoggerInterface

_config/logging.yml

@@ -1,21 +1,34 @@
 ---
 Name: logging
 ---
-# Logging is built up of a chain containing:
+# Core error logging is built up of a chain containing:
 # - A top level \ErrorHandler which registers the error service
 # - A \Logger which acts as the error service
 # - A \HandlerInterface which handles errors for the logger
 # - One or more \FormatterInterface which format errors for the handler
+#
+# Logging for use outside of core error handling also uses the same implementations,
+# but is available without the HandlerInterfaces attached
 SilverStripe\Core\Injector\Injector:
   SilverStripe\Logging\ErrorHandler:
     class: SilverStripe\Logging\MonologErrorHandler
-    properties:
+    calls:
-      Logger: '%$Psr\Log\LoggerInterface'
+      pushDefaultLogger: [ pushLogger, [ '%$Psr\Log\LoggerInterface' ] ]
+      pushErrorHandler: [ pushLogger, [ '%$Psr\Log\LoggerInterface.errorhandler' ] ]
+
+  # Default implementation for use as a standard logger. Up to developers to attach their own
+  # handlers
   Psr\Log\LoggerInterface:
     type: singleton
     class: Monolog\Logger
     constructor:
       - "error-log"
+  # Core error handling
+  Psr\Log\LoggerInterface.errorhandler:
+    type: singleton
+    class: Monolog\Logger
+    constructor:
+      - "error-handler"
     calls:
       pushDisplayErrorHandler: [ pushHandler, [ '%$Monolog\Handler\HandlerInterface' ] ]
 ---

_config/tests.yml

@@ -11,6 +11,7 @@ SilverStripe\Core\Injector\Injector:
         fixtures: '%$SilverStripe\Dev\State\FixtureTestState'
         requirements: '%$SilverStripe\View\Dev\RequirementsTestState'
         ssviewer: '%$SilverStripe\View\Dev\SSViewerTestState'
+        logstate: '%$SilverStripe\Dev\State\LoggerState'
 ---
 Name: kerneltest
 Before: '*'

docs/en/02_Developer_Guides/07_Debugging/01_Error_Handling.md

@@ -4,13 +4,14 @@ summary: Trap, fire and report diagnostic logs, user exceptions, warnings and er
 # Logging and Error Handling
 
 SilverStripe uses Monolog for both error handling and logging. It comes with two default configurations: one for
-development environments, and another for test or live environments. On development environments, SilverStripe will
+logging, and another for core error handling. The core error handling implementation also comes with two default
-deal harshly with any warnings or errors: a full call-stack is shown and execution stops for anything, giving you early
+configurations: one for development environments, and another for test or live environments. On development
-warning of a potential issue to handle.
+environments, SilverStripe will deal harshly with any warnings or errors: a full call-stack is shown and execution
+stops for anything, giving you early warning of a potential issue to handle.
 
 ## Raising errors and logging diagnostic information.
 
-For informational and debug logs, you can use the Logger directly. The Logger is a PSR-3 compatible LoggerInterface and
+For general purpose logging, you can use the Logger directly. The Logger is a PSR-3 compatible LoggerInterface and
 can be accessed via the `Injector`:
 
 ```php
@@ -20,13 +21,15 @@ use SilverStripe\Security\Security;
 
 Injector::inst()->get(LoggerInterface::class)->info('User has logged in: ID #' . Security::getCurrentUser()->ID);
 Injector::inst()->get(LoggerInterface::class)->debug('Query executed: ' . $sql);
+Injector::inst()->get(LoggerInterface::class)->error('Something went wrong, but let\'s continue on...');
 ```
 
 Although you can raise more important levels of alerts in this way, we recommend using PHP's native error systems for
 these instead.
 
-For notice-level and warning-level issues, you should use [user_error](http://www.php.net/user_error) to throw errors
+For notice-level and warning-level issues, you can also use [user_error](http://www.php.net/user_error) to throw errors
-where appropriate. These will not halt execution but will send a message to the PHP error log.
+where appropriate. As with the default Logger implementation these will not halt execution, but will send a message
+to the PHP error log.
 
 ```php
 public function delete()
@@ -48,37 +51,52 @@ public function getRelatedObject()
 }
 ```
 
-For errors that should halt execution, you should use Exceptions. Normally, Exceptions will halt the flow of executuion,
+For errors that should halt execution, you should use Exceptions. Normally, Exceptions will halt the flow of execution,
 but they can be caught with a try/catch clause.
 
 ```php
 throw new \LogicException("Query failed: " . $sql);
 ```
 
-### Accessing the logger via dependency injection.
+### Accessing the logger via dependency injection
 
 It can be quite verbose to call `Injector::inst()->get(LoggerInterface::class)` all the time. More importantly,
 it also means that you're coupling your code to global state, which is a bad design practise. A better
-approach is to use depedency injection to pass the logger in for you. The [Injector](../extending/Injector)
+approach is to use dependency injection to pass the logger in for you. The [Injector](../extending/Injector)
 can help with this. The most straightforward is to specify a `dependencies` config setting, like this:
 
 ```php
+use Psr\Log\LoggerInterface;
 use SilverStripe\Control\Controller;
 
 class MyController extends Controller
 {
     private static $dependencies = [
-        'logger' => '%$Psr\Log\LoggerInterface',
+        'Logger' => '%$' . LoggerInterface::class,
     ];
 
-    // This will be set automatically, as long as MyController is instantiated via Injector
+    /**
-    public $logger;
+     * This will be set automatically, as long as MyController is instantiated via Injector
+     *
+     * @var LoggerInterface
+     */
+    protected $logger;
 
     protected function init()
     {
         $this->logger->debug("MyController::init() called");
         parent::init();
     }
+    
+    /**
+     * @param LoggerInterface $logger
+     * @return $this
+     */
+    public function setLogger(LoggerInterface $logger)
+    {
+        $this->logger = $logger;
+        return $this;
+    }
 }
 ```
 
@@ -98,7 +116,7 @@ E_USER_ERROR if it's going to be **dangerous** or **impossible** to continue wit
 
 ## Configuring error logging
 
-You can configure your logging using Monolog handlers. The handlers should be provided int the `Logger.handlers`
+You can configure your logging using Monolog handlers. The handlers should be provided in the `Logger.handlers`
 configuration setting. Below we have a couple of common examples, but Monolog comes with [many different handlers](https://github.com/Seldaek/monolog/blob/master/doc/02-handlers-formatters-processors.md#handlers)
 for you to try.
 
@@ -145,24 +163,27 @@ SilverStripe\Core\Injector\Injector:
       - "info"
 ```
 
-The log file will be relative to the framework/ path, so "../silverstripe.log" will create a file in your project root.
+The log file will be relative to the main index.php file path (default: inside public/), so "../silverstripe.log" will
+create a file in your project root.
+
+The `info` argument provides the minimum level to start logging at.
 
 ### Disabling the default handler
 
 You can disable a handler by removing its pushHandlers call from the calls option of the Logger service definition.
-The handler key of the default handler is `DisplayErrorHandler`, so you can disable it like this:
+The handler key of the default handler is `pushDisplayErrorHandler`, so you can disable it like this:
 
 ```yaml
 SilverStripe\Core\Injector\Injector:
-  Psr\Log\LoggerInterface:
+  Psr\Log\LoggerInterface.errorhandler:
     calls:
-      DisplayErrorHandler:  %%remove%%
+      pushDisplayErrorHandler:  %%remove%%
 ```
 
 ### Setting a different configuration for dev
 
 In order to set different logging configuration on different environment types, we rely on the environment-specific
-configuration features that the config system proviers. For example, here we have different configuration for dev and
+configuration features that the config system providers. For example, here we have different configuration for dev and
 non-dev.
 
 ```yaml
@@ -172,7 +193,7 @@ Only:
   environment: dev
 ---
 SilverStripe\Core\Injector\Injector:
-  Psr\Log\LoggerInterface:
+  Psr\Log\LoggerInterface.errorhandler:
     calls:
       pushDisplayErrorHandler: [ pushHandler, [ %$DisplayErrorHandler ]] 
   DisplayErrorHandler:
@@ -188,10 +209,21 @@ Except:
   environment: dev
 ---
 SilverStripe\Core\Injector\Injector:
+  # Default logger implementation for general purpose use
   Psr\Log\LoggerInterface:
     calls:
-      pushFileLogHandler: [ pushHandler, [ %$LogFileHandler ]] 
+      # Save system logs to file
+      pushFileLogHandler: [ pushHandler, [ %$LogFileHandler ]]
+  
+  # Core error handler for system use
+  Psr\Log\LoggerInterface.errorhandler:
+    calls:
+      # Save errors to file
+      pushFileLogHandler: [ pushHandler, [ %$LogFileHandler ]]
+      # Format and display errors in the browser/CLI 
       pushDisplayErrorHandler: [ pushHandler, [ %$DisplayErrorHandler ]] 
+  
+  # Custom handler to log to a file
   LogFileHandler:
     class: Monolog\Handler\StreamHandler
     constructor:
@@ -200,12 +232,16 @@ SilverStripe\Core\Injector\Injector:
     properties:
       Formatter: %$Monolog\Formatter\HtmlFormatter
       ContentType: text/html
+  
+  # Handler for displaying errors in the browser or CLI
   DisplayErrorHandler:
     class: SilverStripe\Logging\HTTPOutputHandler
     constructor:
       - "error"
     properties:
       Formatter: %$SilverStripe\Logging\DebugViewFriendlyErrorFormatter
+     
+  # Configuration for the "friendly" error formatter
   SilverStripe\Logging\DebugViewFriendlyErrorFormatter:
     class: SilverStripe\Logging\DebugViewFriendlyErrorFormatter
     properties:
@@ -214,7 +250,7 @@ SilverStripe\Core\Injector\Injector:
 ```
 
 <div class="info" markdown="1">
-In addition to SilverStripe-integrated logging, it is advisable to fall back to PHPs native logging functionality. A
+In addition to SilverStripe-integrated logging, it is advisable to fall back to PHP's native logging functionality. A
 script might terminate before it reaches the SilverStripe error handling, for example in the case of a fatal error. Make
 sure `log_errors` and `error_log` in your PHP ini file are configured.
 </div>
@@ -228,11 +264,12 @@ others.
 ### Replacing the logger
 
 Monolog comes by default with SilverStripe, but you may use another PSR-3 compliant logger, if you wish. To do this,
-set the `Injector.Logger` configuration parameter, providing a new injector definition. For example:
+set the `SilverStripe\Core\Injector\Injector.Monolog\Logger` configuration parameter, providing a new injector
+definition. For example:
 
 ```yaml
 SilverStripe\Core\Injector\Injector:
-  ErrorHandler:
+  SilverStripe\Logging\ErrorHandler:
     class: Logging\Logger
     constructor:
      - 'alternative-logger'
@@ -243,7 +280,8 @@ be ignored.
 
 ### Replacing the error handler
 
-The Injector service `ErrorHandler` is responsible for initialising the error handler. By default it 
+The Injector service `SilverStripe\Logging\ErrorHandler` is responsible for initialising the error handler. By default
+it: 
 
  * Create a `SilverStripe\Logging\MonologErrorHandler` object.
  * Attach the registered service `Psr\Log\LoggerInterface` to it, to start the error handler.
@@ -255,7 +293,7 @@ another. To replace this, you should registered a new service, `ErrorHandlerLoad
 
 ```yaml
 SilverStripe\Core\Injector\Injector:
-  ErrorHandler: 
+  SilverStripe\Logging\ErrorHandler: 
     class: MyApp\CustomErrorHandlerLoader
 ```
 

src/Dev/State/LoggerState.php

@@ -0,0 +1,42 @@
+<?php
+
+namespace SilverStripe\Dev\State;
+
+use Monolog\Handler\NullHandler;
+use Monolog\Logger;
+use Psr\Log\LoggerInterface;
+use SilverStripe\Core\Injector\Injector;
+use SilverStripe\Dev\SapphireTest;
+
+/**
+ * Disables any user configured loggers by pushing a NullHandler during PHPUnit tests.
+ *
+ * This is designed specifically for Monolog. If using another PSR-3 compatible logging package, this will
+ * not do anything.
+ */
+class LoggerState implements TestState
+{
+    public function setUp(SapphireTest $test)
+    {
+        /** @var Logger $userLogger */
+        $userLogger = Injector::inst()->get(LoggerInterface::class);
+        if ($userLogger && $userLogger instanceof Logger) {
+            $userLogger->setHandlers([new NullHandler()]);
+        }
+    }
+
+    public function tearDown(SapphireTest $test)
+    {
+        // noop
+    }
+
+    public function setUpOnce($class)
+    {
+        // noop
+    }
+
+    public function tearDownOnce($class)
+    {
+        // noop
+    }
+}

src/Logging/DebugViewFriendlyErrorFormatter.php

@@ -48,10 +48,12 @@ class DebugViewFriendlyErrorFormatter implements FormatterInterface
      * Set default status code
      *
      * @param int $statusCode
+     * @return $this
      */
     public function setStatusCode($statusCode)
     {
         $this->statusCode = $statusCode;
+        return $this;
     }
 
     /**
@@ -68,10 +70,12 @@ class DebugViewFriendlyErrorFormatter implements FormatterInterface
      * Set friendly title
      *
      * @param string $title
+     * @return $this
      */
     public function setTitle($title)
     {
         $this->friendlyErrorMessage = $title;
+        return $this;
     }
 
     /**
@@ -88,10 +92,12 @@ class DebugViewFriendlyErrorFormatter implements FormatterInterface
      * Set default error body
      *
      * @param string $body
+     * @return $this
      */
     public function setBody($body)
     {
         $this->friendlyErrorDetail = $body;
+        return $this;
     }
 
     public function format(array $record)

src/Logging/DetailedErrorFormatter.php

@@ -79,7 +79,7 @@ class DetailedErrorFormatter implements FormatterInterface
 
     /**
      * Render a developer facing error page, showing the stack trace and details
-     * of the code where the error occured.
+     * of the code where the error occurred.
      *
      * @param int $errno
      * @param string $errstr

src/Logging/HTTPOutputHandler.php

@@ -2,11 +2,11 @@
 
 namespace SilverStripe\Logging;
 
+use Monolog\Formatter\FormatterInterface;
+use Monolog\Handler\AbstractProcessingHandler;
 use SilverStripe\Control\Controller;
 use SilverStripe\Control\Director;
 use SilverStripe\Control\HTTPResponse;
-use Monolog\Handler\AbstractProcessingHandler;
-use Monolog\Formatter\FormatterInterface;
 
 /**
  * Output the error to the browser, with the given HTTP status code.
@@ -79,7 +79,7 @@ class HTTPOutputHandler extends AbstractProcessingHandler
     /**
      * Set a formatter to use if Director::is_cli() is true
      *
-     * @param $cliFormatter
+     * @param FormatterInterface $cliFormatter
      * @return HTTPOutputHandler Return $this to allow chainable calls
      */
     public function setCLIFormatter(FormatterInterface $cliFormatter)
@@ -153,12 +153,12 @@ class HTTPOutputHandler extends AbstractProcessingHandler
             $response = new HTTPResponse();
         }
 
-        // If headers have been sent then these won't be used, and may throw errors that we wont' want to see.
+        // If headers have been sent then these won't be used, and may throw errors that we won't want to see.
         if (!headers_sent()) {
             $response->setStatusCode($this->getStatusCode());
             $response->addHeader('Content-Type', $this->getContentType());
         } else {
-            // To supress errors aboot errors
+            // To suppress errors about errors
             $response->setStatusCode(200);
         }
 

src/Logging/MonologErrorHandler.php

@@ -2,45 +2,97 @@
 
 namespace SilverStripe\Logging;
 
+use InvalidArgumentException;
 use Psr\Log\LoggerInterface;
 use Monolog\ErrorHandler as MonologHandler;
+use SilverStripe\Dev\Deprecation;
 
 class MonologErrorHandler implements ErrorHandler
 {
     /**
-     * @var LoggerInterface
+     * @var LoggerInterface[]
      */
-    private $logger;
+    private $loggers = [];
 
     /**
-     * Set the PSR-3 logger to send errors & exceptions to
+     * Set the PSR-3 logger to send errors & exceptions to. Will overwrite any previously configured
+     * loggers
      *
+     * @deprecated 4.4.0:5.0.0 Use pushHandler() instead
      * @param LoggerInterface $logger
      * @return $this
      */
     public function setLogger(LoggerInterface $logger)
     {
-        $this->logger = $logger;
+        Deprecation::notice('4.4.0', 'Please use pushHandler() instead');
+
+        $this->loggers = [$logger];
         return $this;
     }
 
     /**
-     * Get the PSR-3 logger to send errors & exceptions to
+     * Get the first registered PSR-3 logger to send errors & exceptions to
      *
+     * @deprecated 4.4.0:5.0.0 Use getHandlers() instead
      * @return LoggerInterface
      */
     public function getLogger()
     {
-        return $this->logger;
+        Deprecation::notice('4.4.0', 'Please use getHandlers() instead');
+
+        return reset($this->loggers);
     }
 
+    /**
+     * Adds a PSR-3 logger to send messages to, to the end of the stack
+     *
+     * @param LoggerInterface $logger
+     * @return $this
+     */
+    public function pushLogger(LoggerInterface $logger)
+    {
+        $this->loggers[] = $logger;
+        return $this;
+    }
+
+    /**
+     * Returns the stack of PSR-3 loggers
+     *
+     * @return LoggerInterface[]
+     */
+    public function getLoggers()
+    {
+        return $this->loggers;
+    }
+
+    /**
+     * Set the PSR-3 loggers (overwrites any previously configured values)
+     *
+     * @param LoggerInterface[] $loggers
+     * @return $this
+     */
+    public function setLoggers(array $loggers)
+    {
+        $this->loggers = $loggers;
+        return $this;
+    }
+
+    /**
+     * {@inheritDoc}
+     *
+     * @throws InvalidArgumentException
+     */
     public function start()
     {
-        if (!$this->getLogger()) {
+        $loggers = $this->getLoggers();
-            throw new \InvalidArgumentException("No Logger property passed to MonologErrorHandler."
+        if (empty($loggers)) {
-                . "Is your Injector config correct?");
+            throw new InvalidArgumentException(
+                "No Logger properties passed to MonologErrorHandler. Is your Injector config correct?"
+            );
         }
 
-        MonologHandler::register($this->getLogger());
+        foreach ($loggers as $logger) {
+            MonologHandler::register($logger);
+        }
     }
 }

tests/php/Logging/MonologErrorHandlerTest.php

@@ -2,6 +2,7 @@
 
 namespace SilverStripe\Logging\Tests;
 
+use Psr\Log\LoggerInterface;
 use SilverStripe\Dev\SapphireTest;
 use SilverStripe\Logging\MonologErrorHandler;
 
@@ -9,11 +10,27 @@ class MonologErrorHandlerTest extends SapphireTest
 {
     /**
      * @expectedException \InvalidArgumentException
-     * @expectedExceptionMessageRegExp /No Logger property passed to MonologErrorHandler/
+     * @expectedExceptionMessageRegExp /No Logger properties passed to MonologErrorHandler/
      */
     public function testStartThrowsExceptionWithoutLoggerDefined()
     {
         $handler = new MonologErrorHandler();
         $handler->start();
     }
+
+    public function testSetLoggerResetsStack()
+    {
+        /** @var LoggerInterface $logger */
+        $logger = $this->createMock(LoggerInterface::class);
+
+        $handler = new MonologErrorHandler();
+        $handler->pushLogger($logger)->pushLogger($logger);
+        $this->assertCount(2, $handler->getLoggers(), 'Loggers are pushed to the stack');
+
+        $handler->setLogger($logger);
+        $this->assertCount(1, $handler->getLoggers(), 'setLogger resets stack and pushes');
+
+        $handler->setLoggers([]);
+        $this->assertCount(0, $handler->getLoggers(), 'setLoggers overwrites all configured loggers');
+    }
 }