Replace debug log with respecting log priorities

refs #5638
fixes #5522

config/config.ini.in

@@ -6,35 +6,50 @@ indexController     = "dashboard"
 dateFormat          = "d/m/Y"
 timeFormat          = "g:i A"
 
-; The directory that contains the symlinks to all enabled directories.
+; The directory that contains the symlinks to all enabled directories
 moduleFolder        = "@icingaweb_config_path@/enabledModules"
 
 ; Contains the directories that will be searched for available modules. Modules that
 ; don't exist in these directories can still be symlinked in the module folder, but
-; won't show up in the list of disabled modules.
+; won't show up in the list of disabled modules
 ; modulePath          = "/vagrant/modules:/usr/share/icingaweb/modules"
 
 [logging]
-; General log
+;enable              = false
-enable              = "1"
+; Writing to a Stream
 type                = "stream"
-verbose             = "1"
+; Write data to the following file
 target              = "@icingaweb_log_path@/icingaweb.log"
+; Write data to a PHP stream
+;target              = "php://output"
 
-; For development and debug purposes: Logs additional (non critical) events to a
+;; Writing to the System Log
-; seperate log
+;type        = "syslog"
-debug.enable        = "1"
+;; Prefix all syslog messages generated with the string "Icinga Web"
-debug.type          = "stream"
+;application = "Icinga Web"
-debug.target        = "@icingaweb_log_path@/icingaweb.debug.log"
+;facility    = "LOG_USER"
 
+priority            = 4
+; The default priority is WARN, which means that only events of this priority and above will be tracked.
+; Priority numbers descend in order of importance where EMERG (0) is the most important priority and DEBUG (7) is the
+; least important priority:
+;
+; EMERG   = 0 - Emergency: system is unusable
+; ALERT   = 1 - Alert: action must be taken immediately
+; CRIT    = 2 - Critical: critical conditions
+; ERR     = 3 - Error: error conditions
+; WARN    = 4 - Warning: warning conditions
+; NOTICE  = 5 - Notice: normal but significant condition
+; INFO    = 6 - Informational: informational messages
+; DEBUG   = 7 - Debug: debug messages
 
-; Use ini store to store preferences on local disk
 [preferences]
+; Use INI file storage to save preferences to a local disk
 type                = "ini"
-
-; Use database to store preference into mysql or postgres
-;[preferences]
-;type=db
-;resource=icingaweb-mysql
-
 configPath          = "@icingaweb_config_path@/preferences"
+
+; Use database storage to save preferences in either a MySQL or PostgreSQL database
+;type        = db
+;resource    = icingaweb-mysql
+
+

library/Icinga/Application/ApplicationBootstrap.php

@@ -29,14 +29,13 @@
 
 namespace Icinga\Application;
 
-use \DateTimeZone;
+use DateTimeZone;
-use \Exception;
+use Exception;
-use \Icinga\Application\Modules\Manager as ModuleManager;
+use Icinga\Application\Modules\Manager as ModuleManager;
-use \Icinga\Exception\ConfigurationError;
-use \Icinga\Util\DateTimeFactory;
-use \Icinga\Util\Translator;
-
 use Icinga\Data\ResourceFactory;
+use Icinga\Exception\ConfigurationError;
+use Icinga\Util\DateTimeFactory;
+use Icinga\Util\Translator;
 
 /**
  * This class bootstraps a thin Icinga application layer
@@ -325,10 +324,7 @@ abstract class ApplicationBootstrap
         try {
             $this->moduleManager->loadEnabledModules();
         } catch (Exception $e) {
-            Logger::fatal(
+            Logger::exception(new Exception('Cannot load enabled modules. An exception was thrown:', 0, $e));
-                'Could not load modules. An exception was thrown during bootstrap: %s',
-                $e->getMessage()
-            );
         }
         return $this;
     }

library/Icinga/Application/Logger.php

@@ -29,12 +29,14 @@
 
 namespace Icinga\Application;
 
-use \Zend_Config;
+use Exception;
-use \Zend_Log;
+use Zend_Config;
-use \Zend_Log_Filter_Priority;
+use Zend_Log;
-use \Zend_Log_Writer_Abstract;
+use Zend_Log_Exception;
-use \Zend_Log_Exception;
+use Zend_Log_Filter_Priority;
+use Zend_Log_Writer_Abstract;
 use Icinga\Exception\ConfigurationError;
+use Icinga\Util\File;
 
 /**
  * Zend_Log wrapper
@@ -42,22 +44,7 @@ use Icinga\Exception\ConfigurationError;
 class Logger
 {
     /**
-     * Default log type
+     * Writers attached to the instance of Zend_Log
-     */
-    const DEFAULT_LOG_TYPE = "stream";
-
-    /**
-     * Default log target
-     */
-    const DEFAULT_LOG_TARGET = "./var/log/icingaweb.log";
-
-    /**
-     * Default debug target
-     */
-    const DEFAULT_DEBUG_TARGET = "./var/log/icingaweb.debug.log";
-
-    /**
-     * Array of writers
      *
      * @var array
      */
@@ -71,37 +58,39 @@ class Logger
     private $logger;
 
     /**
-     * Singleton instance
+     * Singleton Logger instance
      *
-     * @var Logger
+     * @var self
      */
     private static $instance;
 
     /**
-     * Queue of unwritten messages
+     * Format for logging exceptions
-     *
-     * @var array
      */
-    private static $queue = array();
+    const LOG_EXCEPTION_FORMAT = <<<'EOD'
+%s: %s
+
+Stacktrace
+----------
+%s
+EOD;
 
     /**
-     * Flag indicate that errors occurred in the past
+     * Create a new Logger
-     *
-     * @var bool
-     */
-    private static $errorsOccurred = false;
-
-    /**
-     * Create a new logger object
      *
      * @param Zend_Config $config
      */
     public function __construct(Zend_Config $config)
     {
-        $this->overwrite($config);
+        $this->logger = new Zend_Log();
+        if ((bool) $config->get('enable', true) === true) {
+            $this->addWriter($config);
+        }
     }
 
     /**
+     * Get the writers attached to the instance of Zend_Log
+     *
      * @return array
      */
     public function getWriters()
@@ -110,131 +99,59 @@ class Logger
     }
 
     /**
-     * Overwrite config to initiated logger
+     * Add writer to the Zend_Log instance
      *
      * @param   Zend_Config $config
      *
-     * @return  self
-     */
-    public function overwrite(Zend_Config $config)
-    {
-        $this->clearLog();
-        try {
-            if ($config->debug && $config->debug->enable == '1') {
-                $this->setupDebugLog($config);
-            }
-        } catch (ConfigurationError $e) {
-            $this->warn('Could not create debug log: ' . $e->getMessage());
-        }
-        if ($config->get('enable', '1') != '0') {
-            $this->setupLog($config);
-        }
-        $this->flushQueue();
-
-        return $this;
-    }
-
-    /**
-     * Configure debug log
-     *
-     * @param Zend_Config $config
-     */
-    private function setupDebugLog(Zend_Config $config)
-    {
-        $type = $config->debug->get("type", self::DEFAULT_LOG_TYPE);
-        $target = $config->debug->get("target", self::DEFAULT_LOG_TARGET);
-        if ($target == self::DEFAULT_LOG_TARGET) {
-            $type = self::DEFAULT_LOG_TYPE;
-        }
-        $this->addWriter($type, $target, Zend_Log::DEBUG);
-    }
-
-    /**
-     * Configure log
-     *
-     * @param Zend_Config $config
-     */
-    private function setupLog(Zend_Config $config)
-    {
-        $type = $config->get("type", self::DEFAULT_LOG_TYPE);
-        $target = $config->get("target", self::DEFAULT_DEBUG_TARGET);
-        if ($target == self::DEFAULT_DEBUG_TARGET) {
-            $type = self::DEFAULT_LOG_TYPE;
-        }
-        $level = Zend_Log::WARN;
-        if ($config->get("verbose", 0) == 1) {
-            $level = Zend_Log::INFO;
-        }
-        $this->addWriter($type, $target, $level);
-    }
-
-    /**
-     * Add writer to log instance
-     *
-     * @param   string  $type       Type, e.g. stream
-     * @param   string  $target     Target, e.g. filename
-     * @param   int     $priority   Value of Zend::* constant
      * @throws  ConfigurationError
      */
-    private function addWriter($type, $target, $priority)
+    public function addWriter($config)
     {
-        $type[0] = strtoupper($type[0]);
+        if (($type = $config->type) === null) {
-        $writerClass = "Zend_Log_Writer_" . $type;
+            throw new ConfigurationError('Logger configuration is missing the type directive');
-
+        }
+        $type = ucfirst(strtolower($type));
+        $writerClass = 'Zend_Log_Writer_' . $type;
         if (!@class_exists($writerClass)) {
-            self::fatal(
+            throw new ConfigurationError('Cannot add log writer of type "' . $type . '". Type does not exist');
-                'Could not add log writer of type "%s". Type does not exist.',
-                $type
-            );
-            return;
         }
         try {
-
+            switch ($type) {
+                case 'Stream':
+                    if (($target = $config->target) === null) {
+                        throw new ConfigurationError(
+                            'Logger configuration is missing the target directive for type stream'
+                        );
+                    }
                     $target = Config::resolvePath($target);
-            // Make sure the permissions for log target file are correct
-            if ($type === 'Stream') {
                     $writer = new $writerClass($target);
                     if (substr($target, 0, 6) !== 'php://' && !file_exists($target)) {
-                    touch($target);
+                        File::create($target);
-                    chmod($target, 0664);
                     }
-            } elseif ($type === 'Syslog') {
+                    break;
-                $writer = new $writerClass();
+                case 'Syslog':
+                    $writer = new $writerClass($config->toArray());
+                    break;
+                default:
+                    throw new ConfigurationError('Logger configuration defines an invalid log type "' . $type . '"');
+            }
+            if (($priority = $config->priority) === null) {
+                $priority = Zend_Log::WARN;
             } else {
-                self::fatal('Got invalid lot type "%s"', $type);
+                $priority = (int) $priority;
             }
             $writer->addFilter(new Zend_Log_Filter_Priority($priority));
-
             $this->logger->addWriter($writer);
             $this->writers[] = $writer;
         } catch (Zend_Log_Exception $e) {
-            self::fatal(
+            throw new ConfigurationError(
-                'Could not add log writer of type %s. An exception was thrown: %s',
+                'Cannot not add log writer of type "' . $type . '". An exception was thrown: '.  $e->getMessage()
-                $type,
-                $e->getMessage()
             );
         }
     }
 
     /**
-     * Flush pending messages to writer
+     * Format a message
-     */
-    public function flushQueue()
-    {
-        try {
-            foreach (self::$queue as $msgTypePair) {
-                $this->logger->log($msgTypePair[0], $msgTypePair[1]);
-            }
-        } catch (Zend_Log_Exception $e) {
-            self::fatal(
-                'Could not flush logs to output. An exception was thrown: %s',
-                $e->getMessage()
-            );
-        }
-    }
-
-    /**
-     * Format output message
      *
      * @param   array $argv
      *
@@ -260,28 +177,13 @@ class Logger
     }
 
     /**
-     * Reset object configuration
+     * Create/overwrite the internal Logger instance
-     */
-    public function clearLog()
-    {
-        $this->logger = null;
-        $this->writers = array();
-        $this->logger = new Zend_Log();
-    }
-
-    /**
-     * Create an instance
      *
      * @param Zend_Config $config
-     *
-     * @return  Logger
      */
     public static function create(Zend_Config $config)
     {
-        if (self::$instance) {
+        self::$instance = new static($config);
-            return self::$instance->overwrite($config);
-        }
-        return self::$instance = new Logger($config);
     }
 
     /**
@@ -317,63 +219,36 @@ class Logger
     }
 
     /**
-     * Log message with severity fatal
+     * Log a message at a priority
+     *
+     * @param  string   $message   Message to log
+     * @param  int      $priority  Priority of message
      */
-    public static function fatal()
+    private static function log($message, $priority = Zend_Log::INFO)
     {
-        self::log(self::formatMessage(func_get_args()), Zend_Log::EMERG);
+        // Swallow messages if the Logger hast not been created
+        if (self::$instance !== null && count(self::$instance->getWriters()) > 0) {
+            self::$instance->logger->log($message, $priority);
+        }
     }
 
     /**
-     * Log message
+     * Log a exception at a priority
      *
-     * @param string    $msg    Message
+     * @param  Exception    $e   Exception to log
-     * @param int       $level  Log level
+     * @param  int          $priority  Priority of message
      */
-    private static function log($msg, $level = Zend_Log::INFO)
+    public static function exception(Exception $e, $priority = Zend_Log::ERR)
     {
-        $logger = self::$instance;
+        $message = array();
-
+        do {
-        if ($level < Zend_Log::WARN && self::$errorsOccurred === false) {
+            $message[] = self::formatMessage(
-            self::$errorsOccurred =true;
+                array(self::LOG_EXCEPTION_FORMAT, get_class($e), $e->getMessage(), $e->getTraceAsString())
-        }
+            );
-
+        } while($e = $e->getPrevious());
-        if (!$logger || !count($logger->getWriters())) {
+        self::log(
-            array_push(self::$queue, array($msg, $level));
+            implode(PHP_EOL, $message),
-            return;
+            $priority
-        }
+        );
-
-        $logger->logger->log($msg, $level);
-    }
-
-    /**
-     * Flag if messages > warning occurred
-     *
-     * @return bool
-     */
-    public static function hasErrorsOccurred()
-    {
-        return self::$errorsOccurred;
-    }
-
-    /**
-     * Access the log queue
-     *
-     * The log queue holds messages that could not be written to output
-     *
-     * @return array
-     */
-    public static function getQueue()
-    {
-        return self::$queue;
-    }
-
-    /**
-     * Reset object state
-     */
-    public static function reset()
-    {
-        self::$queue = array();
-        self::$instance = null;
     }
 }

library/Icinga/Authentication/Manager.php

@@ -310,7 +310,7 @@ class Manager
             $this->persistCurrentUser();
         }
 
-        Logger::info('User "%s" logged in successfully', $credentials->getUsername());
+        Logger::info('User "%s" logged in', $credentials->getUsername());
 
         return true;
     }

test/php/library/Icinga/Application/LoggerTest.php

@@ -33,164 +33,52 @@ namespace Tests\Icinga\Application;
 require_once realpath(__DIR__ . '/../../../../../library/Icinga/Test/BaseTestCase.php');
 // @codingStandardsIgnoreEnd
 
-use \Zend_Config;
+use Zend_Config;
+use Zend_Log;
 use Icinga\Application\Logger;
 use Icinga\Test\BaseTestCase;
 
-/**
- * Test class for Logger
- *
- * @backupStaticAttributes enabled
- **/
 class LoggerTest extends BaseTestCase
 {
-    private $tempDir;
+    /**
-
+     * @backupStaticAttributes enabled
-    private $logTarget;
+     */
-
+    public function testLogfileCreation()
-    private $debugTarget;
-
-    public function setUp()
     {
-        $this->tempDir = tempnam(sys_get_temp_dir(), 'icingaweb-log');
+        $target = tempnam(sys_get_temp_dir(), 'log');
-        unlink($this->tempDir); // tempnam create the file automatically
+        unlink($target);
-
+        Logger::create(
-        if (!is_dir($this->tempDir)) {
+            new Zend_Config(
-            mkdir($this->tempDir, 0755);
+                array(
-        }
-
-        $this->debugTarget = $this->tempDir . '/debug.log';
-        $this->logTarget = $this->tempDir . '/application.log';
-
-        $loggingConfigurationArray = array(
-            'enable'    => 1,
                     'type'      => 'stream',
-            'verbose'   => 1,
+                    'target'    => $target
-            'target'    => $this->logTarget,
+                )
-
-            'debug'     => array(
-                'enable'    => 1,
-                'type'      => 'stream',
-                'target'    => $this->debugTarget
             )
         );
-
+        $this->assertFileExists($target, 'Logger did not create the log file');
-        $loggingConfiguration = new Zend_Config($loggingConfigurationArray);
+        unlink($target);
-
-        Logger::reset();
-        Logger::create($loggingConfiguration);
-
-    }
-
-    public function tearDown()
-    {
-        if (file_exists($this->debugTarget)) {
-            unlink($this->debugTarget);
-        }
-
-        if (file_exists($this->logTarget)) {
-            unlink($this->logTarget);
-        }
-
-        rmdir($this->tempDir);
-    }
-
-    private function getLogData()
-    {
-        return array(
-            explode(PHP_EOL, file_get_contents($this->logTarget)),
-            explode(PHP_EOL, file_get_contents($this->debugTarget))
-        );
     }
 
     /**
-     * Test error messages
+     * @backupStaticAttributes  enabled
+     * @depends                 testLogfileCreation
      */
     public function testLoggingErrorMessages()
     {
-        Logger::error('test-error-1');
+        $target = tempnam(sys_get_temp_dir(), 'log');
-        Logger::error('test-error-2');
+        unlink($target);
-
+        Logger::create(
-        $this->assertFileExists($this->logTarget);
+            new Zend_Config(
-        $this->assertFileExists($this->debugTarget);
-
-        list($main, $debug) = $this->getLogData();
-
-        $this->assertCount(3, $main);
-        $this->assertCount(3, $debug);
-
-        $this->assertContains(' ERR (3): test-error-1', $main[0]);
-        $this->assertContains(' ERR (3): test-error-2', $main[1]);
-
-        $this->assertContains(' ERR (3): test-error-1', $debug[0]);
-        $this->assertContains(' ERR (3): test-error-2', $debug[1]);
-    }
-
-    /**
-     * Test debug log and difference between error and debug messages
-     */
-    public function testLoggingDebugMessages()
-    {
-        Logger::debug('test-debug-1');
-        Logger::error('test-error-1');
-        Logger::debug('test-debug-2');
-
-        $this->assertFileExists($this->logTarget);
-        $this->assertFileExists($this->debugTarget);
-
-        list($main, $debug) = $this->getLogData();
-
-        $this->assertCount(2, $main);
-        $this->assertCount(4, $debug);
-
-        $this->assertContains(' ERR (3): test-error-1', $main[0]);
-
-        $this->assertContains(' DEBUG (7): test-debug-1', $debug[0]);
-        $this->assertContains(' ERR (3): test-error-1', $debug[1]);
-        $this->assertContains(' DEBUG (7): test-debug-2', $debug[2]);
-    }
-
-    public function testLoggingQueueIfNoWriterAvailable()
-    {
-        Logger::reset();
-
-        Logger::error('test-error-1');
-        Logger::debug('test-debug-1');
-        Logger::error('test-error-2');
-
-        list($main, $debug) = $this->getLogData();
-
-        $this->assertCount(1, $main);
-        $this->assertCount(1, $debug);
-
-        $this->assertTrue(Logger::hasErrorsOccurred());
-
-        $queue = Logger::getQueue();
-
-        $this->assertCount(3, $queue);
-
-        $this->assertEquals(
                 array(
-                'test-error-1',
+                    'type'      => 'stream',
-                3
+                    'priority'  => Zend_Log::ERR,
-            ),
+                    'target'    => $target
-            $queue[0]
+                )
-        );
+            )
-
-        $this->assertEquals(
-            array(
-                'test-debug-1',
-                7
-            ),
-            $queue[1]
-        );
-
-        $this->assertEquals(
-            array(
-                'test-error-2',
-                3
-            ),
-            $queue[2]
         );
+        Logger::error('This is a test error');
+        $log = file_get_contents($target);
+        unlink($target);
+        $this->assertContains('This is a test error', $log, 'Log does not contain the error "This is a test error"');
     }
 }