Merge branch 'master' into registry

Conflicts:
	core/ErrorHandler.php
	core/ExceptionHandler.php
	core/FrontController.php
	core/Log.php
	core/Piwik.php

1 files changed, 403 insertions, 140 deletions

diff --git a/core/Log.php b/core/Log.php
index fe1cc9e8f7..a3127bec4d 100644
--- a/core/Log.php
+++ b/core/Log.php
@@ -10,197 +10,460 @@
  */
 namespace Piwik;
 
-use Piwik\Log\APICall;
-use Piwik\Log\Error;
-use Piwik\Log\Exception;
-use Piwik\Log\Message;
-use Piwik\Registry;
+use Piwik\Common;
+use Piwik\Db;
 
 /**
- *
- * @package Piwik
- * @subpackage Log
- * @see Zend_Log, libs/Zend/Log.php
- * @link http://framework.zend.com/manual/en/zend.log.html
+ * Logging utility.
+ * 
+ * You can log messages using one of the public static functions (eg, 'error', 'warning',
+ * 'info', etc.).
+ * 
+ * Currently, Piwik supports the following logging backends:
+ * - logging to the screen
+ * - logging to a file
+ * - logging to a database
+ * 
+ * The logging utility can be configured by manipulating the INI config options in the
+ * [log] section.
  */
-abstract class Log extends \Zend_Log
+class Log
 {
-    protected $logToDatabaseTableName = null;
-    protected $logToDatabaseColumnMapping = null;
-    protected $logToFileFilename = null;
-    protected $fileFormatter = null;
-    protected $screenFormatter = null;
-    protected $currentRequestKey;
+    // log levels
+    const NONE = 0;
+    const ERROR = 1;
+    const WARN = 2;
+    const INFO = 3;
+    const DEBUG = 4;
+    const VERBOSE = 5;
+
+    // config option names
+    const LOG_LEVEL_CONFIG_OPTION = 'log_level';
+    const LOG_WRITERS_CONFIG_OPTION = 'log_writers';
+    const LOGGER_FILE_PATH_CONFIG_OPTION = 'logger_file_path';
+    const STRING_MESSAGE_FORMAT_OPTION = 'string_message_format';
 
     /**
-     * @param string                        $logToFileFilename    filename of logfile
-     * @param \Zend_Log_Formatter_Interface $fileFormatter
-     * @param \Zend_Log_Formatter_Interface $screenFormatter
-     * @param  string                       $logToDatabaseTableName
-     * @param  array                        $logToDatabaseColumnMapping
+     * This event is called when trying to log an object to a file. Plugins can use
+     * this event to convert objects to strings before they are logged.
+     * 
+     * Callback signature: function (&$message, $level, $tag, $datetime, $logger)
+     * 
+     * The $message parameter is the object that is being logged. Event handlers should
+     * check if the object is of a certain type and if it is, set $message to the
+     * string that should be logged.
      */
-    function __construct($logToFileFilename,
-                         $fileFormatter,
-                         $screenFormatter,
-                         $logToDatabaseTableName,
-                         $logToDatabaseColumnMapping)
-    {
-        parent::__construct();
+    const FORMAT_FILE_MESSAGE_EVENT = 'Log.formatFileMessage';
+
+    /**
+     * This event is called when trying to log an object to the screen. Plugins can use
+     * this event to convert objects to strings before they are logged.
+     * 
+     * Callback signature: function (&$message, $level, $tag, $datetiem, $logger)
+     * 
+     * The $message parameter is the object that is being logged. Event handlers should
+     * check if the object is of a certain type and if it is, set $message to the
+     * string that should be logged.
+     * 
+     * The result of this callback can be HTML so no sanitization is done on the result.
+     * This means YOU MUST SANITIZE THE MESSAGE YOURSELF if you use this event.
+     */
+    const FORMAT_SCREEN_MESSAGE_EVENT = 'Log.formatScreenMessage';
+
+    /**
+     * This event is called when trying to log an object to a database table. Plugins can use
+     * this event to convert objects to strings before they are logged.
+     * 
+     * Callback signature: function (&$message, $level, $tag, $datetiem, $logger)
+     * 
+     * The $message parameter is the object that is being logged. Event handlers should
+     * check if the object is of a certain type and if it is, set $message to the
+     * string that should be logged.
+     */
+    const FORMAT_DATABASE_MESSAGE_EVENT = 'Log.formatDatabaseMessage';
 
-        $this->currentRequestKey = substr(Common::generateUniqId(), 0, 8);
+    /**
+     * The singleton Log instance.
+     * 
+     * @var Log
+     */
+    private static $instance = null;
 
-        $log_dir = Config::getInstance()->log['logger_file_path'];
-        if ($log_dir[0] != '/' && $log_dir[0] != DIRECTORY_SEPARATOR) {
-            $log_dir = PIWIK_USER_PATH . '/' . $log_dir;
+    /**
+     * Returns the singleton Log instance or creates it if it doesn't exist.
+     * 
+     * @return Log
+     */
+    public static function getInstance()
+    {
+        if (self::$instance === null) {
+            self::$instance = new Log();
         }
-        $this->logToFileFilename = $log_dir . '/' . $logToFileFilename;
+        return self::$instance;
+    }
 
-        $this->fileFormatter = $fileFormatter;
-        $this->screenFormatter = $screenFormatter;
-        $this->logToDatabaseTableName = Common::prefixTable($logToDatabaseTableName);
-        $this->logToDatabaseColumnMapping = $logToDatabaseColumnMapping;
+    /**
+     * Unsets the singleton instance so it will be re-created the next time getInstance() is
+     * called. For testing purposes only.
+     */
+    public static function clearInstance()
+    {
+        self::$instance = null;
     }
 
-    function addWriteToFile()
+    /**
+     * The current logging level. Everything of equal or greater priority will be logged.
+     * Everything else will be ignored.
+     * 
+     * @var int
+     */
+    private $currentLogLevel = self::WARN;
+
+    /**
+     * The array of callbacks executed when logging to a file. Each callback writes a log
+     * message to a logging backend.
+     * 
+     * @var array
+     */
+    private $writers = array();
+
+    /**
+     * The log message format string that turns a tag name, date-time and message into
+     * one string to log.
+     * 
+     * @var string
+     */
+    private $logMessageFormat = "[%tag%:%datetime%] %message%";
+
+    /**
+     * If we're logging to a file, this is the path to the file to log to.
+     * 
+     * @var string
+     */
+    private $logToFilePath;
+
+    /**
+     * True if we're currently setup to log to a screen, false if otherwise.
+     * 
+     * @var bool
+     */
+    private $loggingToScreen;
+
+    /**
+     * Constructor.
+     */
+    private function __construct()
     {
-        Filesystem::mkdir(dirname($this->logToFileFilename));
-        $writerFile = new \Zend_Log_Writer_Stream($this->logToFileFilename);
-        $writerFile->setFormatter($this->fileFormatter);
-        $this->addWriter($writerFile);
+        $logConfig = Config::getInstance()->log;
+        $this->setCurrentLogLevelFromConfig($logConfig);
+        $this->setLogWritersFromConfig($logConfig);
+        $this->setLogFilePathFromConfig($logConfig);
+        $this->setStringLogMessageFormat($logConfig);
+        $this->disableLoggingBasedOnConfig($logConfig);
     }
 
-    function addWriteToNull()
+    /**
+     * Logs a message using the ERROR log level.
+     * 
+     * Note: Messages logged with the ERROR level are always logged to the screen in addition
+     * to configured writers.
+     * 
+     * @param string $message The log message. This can be a sprintf format string.
+     * @param ... mixed Optional sprintf params.
+     */
+    public static function error($message /* ... */)
     {
-        $this->addWriter(new \Zend_Log_Writer_Null);
+        self::log(self::ERROR, $message, array_slice(func_get_args(), 1));
     }
 
-    function addWriteToDatabase()
+    /**
+     * Logs a message using the WARNING log level.
+     * 
+     * @param string $message The log message. This can be a sprintf format string.
+     * @param ... mixed Optional sprintf params.
+     */
+    public static function warning($message /* ... */)
     {
-        $writerDb = new \Zend_Log_Writer_Db(
-            Db::get(),
-            $this->logToDatabaseTableName,
-            $this->logToDatabaseColumnMapping);
+        self::log(self::WARN, $message, array_slice(func_get_args(), 1));
+    }
 
-        $this->addWriter($writerDb);
+    /**
+     * Logs a message using the INFO log level.
+     * 
+     * @param string $message The log message. This can be a sprintf format string.
+     * @param ... mixed Optional sprintf params.
+     */
+    public static function info($message /* ... */)
+    {
+        self::log(self::INFO, $message, array_slice(func_get_args(), 1));
     }
 
-    function addWriteToScreen()
+    /**
+     * Logs a message using the DEBUG log level.
+     * 
+     * @param string $message The log message. This can be a sprintf format string.
+     * @param ... mixed Optional sprintf params.
+     */
+    public static function debug($message /* ... */)
     {
-        $writerScreen = new \Zend_Log_Writer_Stream('php://output');
-        $writerScreen->setFormatter($this->screenFormatter);
-        $this->addWriter($writerScreen);
+        self::log(self::DEBUG, $message, array_slice(func_get_args(), 1));
     }
 
-    public function getWritersCount()
+    /**
+     * Logs a message using the VERBOSE log level.
+     * 
+     * @param string $message The log message. This can be a sprintf format string.
+     * @param ... mixed Optional sprintf params.
+     */
+    public static function verbose($message /* ... */)
     {
-        return count($this->_writers);
+        self::log(self::VERBOSE, $message, array_slice(func_get_args(), 1));
     }
 
     /**
-     * Log an event
-     * @param string $event
-     * @param int $priority
-     * @param null $extras
-     * @throws \Zend_Log_Exception
-     * @return void
+     * Creates log message combining logging info including a log level, tag name,
+     * date time, and caller provided log message. The log message can be set through
+     * the string_message_format ini option in the [log] section. By default it will
+     * create log messages like:
+     * 
+     * [tag:datetime] log message
+     * 
+     * @param int $level
+     * @param string $tag
+     * @param string $datetime
+     * @param string $message
+     * @return string
      */
-    public function log($event, $priority, $extras = null)
+    public function formatMessage($level, $tag, $datetime, $message)
     {
-        // sanity checks
-        if (empty($this->_writers)) {
-            throw new \Zend_Log_Exception('No writers were added');
-        }
+        return str_replace(
+            array("%tag%", "%message%", "%datetime%", "%level%"),
+            array($tag, $message, $datetime, $this->getStringLevel($level)),
+            $this->logMessageFormat
+        );
+    }
 
-        $event['timestamp'] = date('Y-m-d H:i:s');
-        $event['requestKey'] = $this->currentRequestKey;
-        // pack into event required by filters and writers
-        $event = array_merge($event, $this->_extras);
+    private function setLogWritersFromConfig($logConfig)
+    {
+        // set the log writers
+        $logWriters = $logConfig[self::LOG_WRITERS_CONFIG_OPTION];
 
-        // one message must stay on one line
-        if (isset($event['message'])) {
-            $event['message'] = str_replace(array(PHP_EOL, "\n"), " ", $event['message']);
-        }
+        $logWriters = array_map('trim', $logWriters);
+        foreach ($logWriters as $writerName) {
+            $writer = $this->createWriterByName($writerName);
+            if (!empty($writer)) {
+                $this->writers[] = $writer;
+            }
 
-        // Truncate the backtrace which can be too long to display in the browser
-        if (!empty($event['backtrace'])) {
-            $maxSizeOutputBytes = 1024 * 1024; // no more than 1M output please
-            $truncateBacktraceLineAfter = 1000;
-            $maxLines = ceil($maxSizeOutputBytes / $truncateBacktraceLineAfter);
-            $bt = explode("\n", $event['backtrace']);
-            foreach ($bt as $count => &$line) {
-                if (strlen($line) > $truncateBacktraceLineAfter) {
-                    $line = substr($line, 0, $truncateBacktraceLineAfter) . '...';
-                }
-                if ($count > $maxLines) {
-                    $line .= "\nTruncated error message.";
-                    break;
-                }
+            if ($writerName == 'screen') {
+                $this->loggingToScreen = true;
             }
-            $event['backtrace'] = implode("\n", $bt);
         }
-        // abort if rejected by the global filters
-        foreach ($this->_filters as $filter) {
-            if (!$filter->accept($event)) {
-                return;
+    }
+
+    private function setCurrentLogLevelFromConfig($logConfig)
+    {
+        if (!empty($logConfig[self::LOG_LEVEL_CONFIG_OPTION])) {
+            $logLevel = $this->getLogLevelFromStringName(self::LOG_LEVEL_CONFIG_OPTION);
+
+            if ($logLevel >= self::NONE // sanity check
+                && $logLevel <= self::VERBOSE
+            ) {
+                $this->currentLogLevel = $logLevel;
             }
         }
+    }
 
-        // send to each writer
-        foreach ($this->_writers as $writer) {
-            $writer->write($event);
+    private function setStringLogMessageFormat($logConfig)
+    {
+        if (isset($logConfig['string_message_format'])) {
+            $this->logMessageFormat = $logConfig['string_message_format'];
         }
     }
 
+    private function setLogFilePathFromConfig($logConfig)
+    {
+        $logPath = $logConfig[self::LOGGER_FILE_PATH_CONFIG_OPTION];
+        if ($logPath[0] != '/' && $logPath[0] != DIRECTORY_SEPARATOR) {
+            $logPath = PIWIK_USER_PATH . '/' . $logPath;
+        }
+        if (is_dir($logPath)) {
+            $logPath .= '/piwik.log';
+        }
+        $this->logToFilePath = $logPath;
+    }
 
-    /**
-     * Create log object
-     * @throws Exception
-     */
-    static public function make()
+    private function createWriterByName($writerName)
     {
-        $configAPI = Config::getInstance()->log;
+        $writer = false;
+        if ($writerName == 'file') {
+            $writer = array($this, 'logToFile');
+        } else if ($writerName == 'screen') {
+            $writer = array($this, 'logToScreen');
+        } else if ($writerName == 'database') {
+            $writer = array($this, 'logToDatabase');
+        }
+        return $writer;
+    }
 
-        /** @var Log[] $aLoggers */
-        $aLoggers = array(
-            'logger_api_call' => new APICall,
-            'logger_exception' => new Exception,
-            'logger_error' => new Error,
-            'logger_message' => new Message,
-        );
+    private function logToFile($level, $tag, $datetime, $message)
+    {
+        if (is_string($message)) {
+            $message = $this->formatMessage($level, $tag, $datetime, $message);
+        } else {
+            Piwik_PostEvent(self::FORMAT_FILE_MESSAGE_EVENT, array(&$message, $level, $tag, $datetime, $this));
+        }
 
-        foreach ($configAPI as $loggerType => $aRecordTo) {
-            if (isset($aLoggers[$loggerType])) {
-                $logger = $aLoggers[$loggerType];
-
-                foreach ($aRecordTo as $recordTo) {
-                    switch ($recordTo) {
-                        case 'screen':
-                            $logger->addWriteToScreen();
-                            break;
-
-                        case 'database':
-                            $logger->addWriteToDatabase();
-                            break;
-
-                        case 'file':
-                            $logger->addWriteToFile();
-                            break;
-
-                        default:
-                            throw new \Exception("'$recordTo' is not a valid Log type. Valid logger types are: screen, database, file.");
-                            break;
-                    }
-                }
-            }
+        if (empty($message)) {
+            return;
+        }
+
+        file_put_contents($this->logToFilePath, $message . "\n", FILE_APPEND);
+    }
+
+    private function logToScreen($level, $tag, $datetime, $message)
+    {
+        if (is_string($message)) {
+            $message = Common::sanitizeInputValue($this->formatMessage($level, $tag, $datetime, $message));
+            $message = '<pre>' . $message . '</pre>';
+        } else {
+            Piwik_PostEvent(self::FORMAT_SCREEN_MESSAGE_EVENT, array(&$message, $level, $tag, $datetime, $this));
+        }
+
+        if (empty($message)) {
+            return;
+        }
+
+        echo $message . "\n";
+    }
+
+    private function logToDatabase($level, $tag, $datetime, $message)
+    {
+        if (is_string($message)) {
+            $message = $this->formatMessage($level, $tag, $datetime, $message);
+        } else {
+            Piwik_PostEvent(self::FORMAT_DATABASE_MESSAGE_EVENT, array(&$message, $level, $tag, $datetime, $this));
         }
 
-        foreach ($aLoggers as $loggerType => $logger) {
-            if ($logger->getWritersCount() == 0) {
-                $logger->addWriteToNull();
+        if (empty($message)) {
+            return;
+        }
+
+        $sql = "INSERT INTO " . Common::prefixTable('logger_message')
+             . " (tag, timestamp, level, message)"
+             . " VALUES (?, ?, ?, ?)";
+        Db::query($sql, array($tag, $datetime, $level, (string)$message));
+    }
+
+    private function doLog($level, $message, $sprintfParams = array())
+    {
+        if ($this->shouldLoggerLog($level)) {
+            $datetime = date("Y-m-d H:i:s");
+            if (is_string($message)
+                && !empty($sprintfParams)
+            ) {
+                $message = vsprintf($message, $sprintfParams);
+            }
+
+            $backtrace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
+            $tag = Plugin::getPluginNameFromBacktrace($backtrace);
+
+            // if we can't determine the plugin, use the name of the calling class
+            if ($tag == false) {
+                $tag = $this->getClassNameThatIsLogging($backtrace);
             }
-            Registry::set($loggerType, $logger);
+
+            $this->writeMessage($level, $tag, $datetime, $message);
         }
     }
 
-}
+    private function writeMessage($level, $tag, $datetime, $message)
+    {
+        foreach ($this->writers as $writer) {
+            call_user_func($writer, $level, $tag, $datetime, $message);
+        }
 
+        // errors are always printed to screen
+        if ($level == self::ERROR
+            && !$this->loggingToScreen
+        ) {
+            $this->logToScreen($level, $tag, $datetime, $message);
+        }
+    }
+
+    private static function log($level, $message, $sprintfParams)
+    {
+        self::getInstance()->doLog($level, $message, $sprintfParams);
+    }
+
+    private function shouldLoggerLog($level)
+    {
+        return $level <= $this->currentLogLevel;
+    }
+
+    private function disableLoggingBasedOnConfig($logConfig)
+    {
+        $disableLogging = false;
+
+        if (!empty($logConfig['log_only_when_cli'])
+            && !Common::isPhpCliMode()
+        ) {
+            $disableLogging = true;
+        }
+
+        if (!empty($logConfig['log_only_when_debug_parameter'])
+            && !isset($_REQUEST['debug'])
+        ) {
+            $disableLogging = true;
+        }
+
+        if ($disableLogging) {
+            $this->currentLogLevel = self::NONE;
+        }
+    }
+
+    private function getLogLevelFromStringName($name)
+    {
+        switch (strtoupper($name)) {
+            case 'NONE':
+                return self::NONE;
+            case 'ERROR':
+                return self::ERROR;
+            case 'WARN':
+                return self::WARN;
+            case 'INFO':
+                return self::INFO;
+            case 'DEBUG':
+                return self::DEBUG;
+            case 'VERBOSE':
+                return self::VERBOSE;
+            default:
+                return -1;
+        }
+    }
+
+    private function getStringLevel($level)
+    {
+        static $levelToName = array(
+            self::NONE => 'NONE',
+            self::ERROR => 'ERROR',
+            self::WARN => 'WARN',
+            self::INFO => 'INFO',
+            self::DEBUG => 'DEBUG',
+            self::VERBOSE => 'VERBOSE'
+        );
+        return $levelToName[$level];
+    }
+
+    private function getClassNameThatIsLogging($backtrace)
+    {
+        foreach ($backtrace as $tracepoint) {
+            if (isset($tracepoint['class'])
+                && $tracepoint['class'] != "Piwik\\Log"
+            ) {
+                return $tracepoint['class'];
+            }
+        }
+        return false;
+    }
+}