Initial logging proposal.

C.f. #112

Add logging to the Mustache Engine.

 * Add a Logger interface.
 * If a Logger instance is passed to the Engine constructor
   (or added later via setLogger) template compiling,
   caching, errors and missing partials will be logged.
 * Add a Stream Logger and Monolog Logger implementation. You
   should use the Monolog Logger.

src/Mustache/Engine.php

@@ -34,12 +34,13 @@ class Mustache_Engine
     // Environment
     private $templateClassPrefix = '__Mustache_';
     private $cache = null;
+    private $cacheFileMode = null;
     private $loader;
     private $partialsLoader;
     private $helpers;
     private $escape;
     private $charset = 'UTF-8';
-    private $cacheFileMode = null;
+    private $logger;
 
     /**
      * Mustache class constructor.
@@ -81,6 +82,9 @@ class Mustache_Engine
      *
      *         // Character set for `htmlspecialchars`. Defaults to 'UTF-8'. Use 'UTF-8'.
      *         'charset' => 'ISO-8859-1',
+     *
+     *         // A Mustache Logger instance. No logging will occur unless this is set.
+     *         'logger' => new Mustache_StreamLogger('php://stderr'),
      *     );
      *
      * @param array $options (default: array())
@@ -126,6 +130,10 @@ class Mustache_Engine
         if (isset($options['charset'])) {
             $this->charset = $options['charset'];
         }
+
+        if (isset($options['logger'])) {
+            $this->setLogger($options['logger']);
+        }
     }
 
     /**
@@ -330,6 +338,26 @@ class Mustache_Engine
         $this->getHelpers()->remove($name);
     }
 
+    /**
+     * Set the Mustache Logger instance.
+     *
+     * @param Mustache_Logger $logger
+     */
+    public function setLogger(Mustache_Logger $logger)
+    {
+        $this->logger = $logger;
+    }
+
+    /**
+     * Get the current Mustache Logger instance.
+     *
+     * @return Mustache_Logger
+     */
+    public function getLogger()
+    {
+        return $this->logger;
+    }
+
     /**
      * Set the Mustache Tokenizer instance.
      *
@@ -453,7 +481,12 @@ class Mustache_Engine
         try {
             return $this->loadSource($this->getPartialsLoader()->load($name));
         } catch (InvalidArgumentException $e) {
-            // If the named partial cannot be found, return null.
+            // If the named partial cannot be found, log then return null.
+            $this->log(
+                Mustache_Logger::WARNING,
+                sprintf('Partial not found: "%s"', $name),
+                array('name' => $name)
+            );
         }
     }
 
@@ -496,15 +529,33 @@ class Mustache_Engine
             if (!class_exists($className, false)) {
                 if ($fileName = $this->getCacheFilename($source)) {
                     if (!is_file($fileName)) {
+                        $this->log(
+                            Mustache_Logger::DEBUG,
+                            sprintf('Writing "%s" class to template cache: "%s"', $className, $fileName),
+                            array('className' => $className, 'fileName' => $fileName)
+                        );
+
                         $this->writeCacheFile($fileName, $this->compile($source));
                     }
 
                     require_once $fileName;
                 } else {
+                    $this->log(
+                        Mustache_Logger::WARNING,
+                        sprintf('Template cache disabled, evaluating "%s" class at runtime', $className),
+                        array('className' => $className)
+                    );
+
                     eval('?>'.$this->compile($source));
                 }
             }
 
+            $this->log(
+                Mustache_Logger::DEBUG,
+                sprintf('Instantiating template: "%s"', $className),
+                array('className' => $className)
+            );
+
             $this->templates[$className] = new $className($this);
         }
 
@@ -553,6 +604,12 @@ class Mustache_Engine
         $tree = $this->parse($source);
         $name = $this->getTemplateClassName($source);
 
+        $this->log(
+            Mustache_Logger::INFO,
+            sprintf('Compiling template to "%s" class', $name),
+            array('name' => $name)
+        );
+
         return $this->getCompiler()->compile($source, $tree, $name, isset($this->escape), $this->charset);
     }
 
@@ -573,7 +630,7 @@ class Mustache_Engine
     /**
      * Helper method to dump a generated Mustache Template subclass to the file cache.
      *
-     * @throws RuntimeException if unable to create the cache directory or write $fileName
+     * @throws RuntimeException if unable to create the cache directory or write to $fileName.
      *
      * @param string $fileName
      * @param string $source
@@ -584,12 +641,25 @@ class Mustache_Engine
     {
         $dirName = dirname($fileName);
         if (!is_dir($dirName)) {
+            $this->log(
+                Mustache_Logger::INFO,
+                sprintf('Creating Mustache template cache directory: "%s"', $dirName),
+                array('dirName' => $dirName)
+            );
+
             @mkdir($dirName, 0777, true);
             if (!is_dir($dirName)) {
                 throw new RuntimeException(sprintf('Failed to create cache directory "%s".', $dirName));
             }
+
         }
 
+        $this->log(
+            Mustache_Logger::DEBUG,
+            sprintf('Caching compiled template to "%s"', dirname($fileName)),
+            array('filename' => $fileName)
+        );
+
         $tempFile = tempnam($dirName, basename($fileName));
         if (false !== @file_put_contents($tempFile, $source)) {
             if (@rename($tempFile, $fileName)) {
@@ -598,8 +668,28 @@ class Mustache_Engine
 
                 return;
             }
+
+            $this->log(
+                Mustache_Logger::ERROR,
+                sprintf('Unable to rename Mustache temp cache file: "%s" -> "%s"', $tempFile, $fileName),
+                array('tempFile' => $tempFile, 'fileName' => $fileName)
+            );
         }
 
         throw new RuntimeException(sprintf('Failed to write cache file "%s".', $fileName));
     }
+
+    /**
+     * Add a log record if logging is enabled.
+     *
+     * @param  integer $level   The logging level
+     * @param  string  $message The log message
+     * @param  array   $context The log context
+     */
+    private function log($level, $message, array $context = array())
+    {
+        if (isset($this->logger)) {
+            $this->logger->log($level, $message, $context);
+        }
+    }
 }

src/Mustache/Logger.php

@@ -0,0 +1,75 @@
+<?php
+
+/*
+ * This file is part of Mustache.php.
+ *
+ * (c) 2012 Justin Hileman
+ *
+ * For the full copyright and license information, please view the LICENSE
+ * file that was distributed with this source code.
+ */
+
+/**
+ * The Mustache Logger interface.
+ */
+interface Mustache_Logger
+{
+    /**
+     * Detailed debug information
+     */
+    const DEBUG = 100;
+
+    /**
+     * Interesting events
+     *
+     * Examples: User logs in, SQL logs.
+     */
+    const INFO = 200;
+
+    /**
+     * Uncommon events
+     */
+    const NOTICE = 250;
+
+    /**
+     * Exceptional occurrences that are not errors
+     *
+     * Examples: Use of deprecated APIs, poor use of an API,
+     * undesirable things that are not necessarily wrong.
+     */
+    const WARNING = 300;
+
+    /**
+     * Runtime errors
+     */
+    const ERROR = 400;
+
+    /**
+     * Critical conditions
+     *
+     * Example: Application component unavailable, unexpected exception.
+     */
+    const CRITICAL = 500;
+
+    /**
+     * Action must be taken immediately
+     *
+     * Example: Entire website down, database unavailable, etc.
+     * This should trigger the SMS alerts and wake you up.
+     */
+    const ALERT = 550;
+
+    /**
+     * Urgent alert.
+     */
+    const EMERGENCY = 600;
+
+    /**
+     * Adds a log record.
+     *
+     * @param  integer $level   The logging level
+     * @param  string  $message The log message
+     * @param  array   $context The log context
+     */
+    public function log($level, $message, array $context = array());
+}

src/Mustache/Logger/AbstractLogger.php

@@ -0,0 +1,98 @@
+<?php
+
+/*
+ * This file is part of Mustache.php.
+ *
+ * (c) 2012 Justin Hileman
+ *
+ * For the full copyright and license information, please view the LICENSE
+ * file that was distributed with this source code.
+ */
+
+/**
+ * An abstract Mustache Logger implementation.
+ */
+abstract class Mustache_Logger_AbstractLogger implements Mustache_Logger
+{
+    protected static $levels = array(
+        100 => 'DEBUG',
+        200 => 'INFO',
+        250 => 'NOTICE',
+        300 => 'WARNING',
+        400 => 'ERROR',
+        500 => 'CRITICAL',
+        550 => 'ALERT',
+        600 => 'EMERGENCY',
+    );
+
+    /**
+     * Abstract Logger constructor.
+     *
+     * @throws InvalidArgumentException if the logging level is unknown.
+     *
+     * @param  integer $level The minimum logging level which will be written
+     */
+    public function __construct($level = self::ERROR)
+    {
+        if (!array_key_exists($level, self::$levels)) {
+            throw new InvalidArgumentException('Unexpected logging level: ' . $level);
+        }
+
+        $this->level = $level;
+    }
+
+    /**
+     * Adds a log record.
+     *
+     * @see Mustache_Logger_AbstractLogger::write
+     *
+     * @param  integer $level   The logging level
+     * @param  string  $message The log message
+     * @param  array   $context The log context
+     */
+    public function log($level, $message, array $context = array())
+    {
+        if ($level >= $this->level) {
+            $this->writeLog($level, $message, $context);
+        }
+    }
+
+    /**
+     * Gets the name of the logging level.
+     *
+     * @throws InvalidArgumentException if the logging level is unknown.
+     *
+     * @param  integer $level
+     *
+     * @return string
+     */
+    public static function getLevelName($level)
+    {
+        if (!array_key_exists($level, self::$levels)) {
+            throw new InvalidArgumentException('Unexpected logging level: ' . $level);
+        }
+
+        return self::$levels[$level];
+    }
+
+    /**
+     * Format a log line for output.
+     *
+     * @param  integer $level   The logging level
+     * @param  string  $message The log message
+     * @param  array   $context The log context
+     */
+    public static function formatLine($level, $message, array $context = array())
+    {
+        return sprintf('%s: %s %s', self::getLevelName($level), (string) $message, json_encode($context));
+    }
+
+    /**
+     * Write a record to the log. Implemented by subclasses.
+     *
+     * @param  integer $level   The logging level
+     * @param  string  $message The log message
+     * @param  array   $context The log context
+     */
+    abstract protected function write($level, $message, array $context = array());
+}

src/Mustache/Logger/MonologLogger.php

@@ -0,0 +1,59 @@
+<?php
+
+/*
+ * This file is part of Mustache.php.
+ *
+ * (c) 2012 Justin Hileman
+ *
+ * For the full copyright and license information, please view the LICENSE
+ * file that was distributed with this source code.
+ */
+
+/**
+ * A Mustache Monolog Logger adapter.
+ */
+class MonologLogger extends Mustache_Logger_AbstractLogger
+{
+    protected $logger;
+
+    /**
+     * @param \Monolog\Logger $logger
+     */
+    public function __construct($logger)
+    {
+        // not typehinting this because PHP 5.2 that's why.
+        if (!is_a($logger, 'Monolog\\Logger')) {
+            throw new InvalidArgumentException('MonologLogger requires a Monolog\\Logger instance.');
+        }
+
+        $this->logger = $logger;
+    }
+
+    /**
+     * Adds a log record.
+     *
+     * Overload the AbstractLogger::log method, because all log messages should
+     * be passed through to Monolog regardless of the log level. Monolog will
+     * handle ignoring the messages it doesn't care about.
+     *
+     * @param  integer $level   The logging level
+     * @param  string  $message The log message
+     * @param  array   $context The log context
+     */
+    public function log($level, $message, array $context = array())
+    {
+        $this->write($level, $message, $context);
+    }
+
+    /**
+     * Write a record to the log.
+     *
+     * @param  integer $level   The logging level
+     * @param  string  $message The log message
+     * @param  array   $context The log context
+     */
+    protected function write($level, $message, array $context = array())
+    {
+        $this->logger->addRecord($level, $message, $context);
+    }
+}

src/Mustache/Logger/StreamLogger.php

@@ -0,0 +1,63 @@
+<?php
+
+/*
+ * This file is part of Mustache.php.
+ *
+ * (c) 2012 Justin Hileman
+ *
+ * For the full copyright and license information, please view the LICENSE
+ * file that was distributed with this source code.
+ */
+
+/**
+ * A Mustache Stream Logger.
+ *
+ * The Stream Logger wraps a file resource instance (such as a stream) or a
+ * stream URL. All log messages over the threshold level will be appended to
+ * this stream.
+ *
+ * Hint: Try `php://stderr` for your stream URL.
+ */
+class StreamLogger extends Mustache_Logger_AbstractLogger
+{
+    protected $stream = null;
+    protected $url    = null;
+
+    /**
+     * @param string  $stream Resource instance or URL
+     * @param integer $level  The minimum logging level at which this handler will be triggered
+     */
+    public function __construct($stream, $level = Mustache_Logger::ERROR)
+    {
+        parent::__construct($level);
+
+        if (is_resource($stream)) {
+            $this->stream = $stream;
+        } else {
+            $this->url = $stream;
+        }
+    }
+
+    /**
+     * Write a record to the log.
+     *
+     * @param  integer $level   The logging level
+     * @param  string  $message The log message
+     * @param  array   $context The log context
+     */
+    protected function write($level, $message, array $context = array())
+    {
+        if ($this->stream === null) {
+            if (!isset($this->url)) {
+                throw new LogicException('Missing stream url, the stream can not be opened. This may be caused by a premature call to close().');
+            }
+
+            $this->stream = fopen($this->url, 'a');
+            if (!is_resource($this->stream)) {
+                throw new UnexpectedValueException(sprintf('The stream or file "%s" could not be opened.', $this->url));
+            }
+        }
+
+        fwrite($this->stream, self::formatLine($level, $message, $context));
+    }
+}