From 9b3580165087a65029f0107ac973a386e80a23cd Mon Sep 17 00:00:00 2001 From: Bryan Davis Date: Thu, 20 Mar 2014 22:51:45 -0600 Subject: [PATCH] Add a PSR-3 based logging interface The MWLogger class is actually a thin wrapper around any PSR-3 LoggerInterface implementation. Named MWLogger instances can be obtained from the MWLogger::getInstance() static method. MWLogger expects a class implementing the MWLoggerSpi interface to act as a factory for new MWLogger instances. A concrete MWLoggerSpi implementation using the Monolog library is also provided. New classes introduced: ; MWLogger : PSR-3 compatible logger that wraps any \Psr\Log\LoggerInterface implementation ; MWLoggerSpi : Service provider interface for MWLogger factories ; MWLoggerNullSpi : MWLoggerSpi for creating instances that discard all log events ; MWLoggerMonologSpi : MWLoggerSpi for creating instances backed by the monolog logging library ; MWLoggerMonologHandler : Monolog handler that replicates the udp2log and file logging functionality of wfErrorLog() ; MWLoggerMonologProcessor : Monolog log processer that adds host:wfHostname() and wiki:wfWikiID() to all records New globals introduced: ; $wgMWLoggerDefaultSpi : Default service provider interface to use with MWLogger ; $wgMWLoggerMonologSpiConfig : Configuration for MWLoggerMonologSpi describing how to configure the Monolog logger instances. This change relies on the Composer managed Psr\Log and Monolog libraries introduced in Ie667944. Change-Id: I5c822995a181a38c844f4a13cb172297827e0031 --- docs/mwlogger.txt | 59 +++++ includes/AutoLoader.php | 6 + includes/DefaultSettings.php | 37 +++ includes/debug/logger/Logger.php | 212 +++++++++++++++ includes/debug/logger/NullSpi.php | 54 ++++ includes/debug/logger/Spi.php | 45 ++++ includes/debug/logger/monolog/Handler.php | 212 +++++++++++++++ includes/debug/logger/monolog/Processor.php | 47 ++++ includes/debug/logger/monolog/Spi.php | 279 ++++++++++++++++++++ 9 files changed, 951 insertions(+) create mode 100644 docs/mwlogger.txt create mode 100644 includes/debug/logger/Logger.php create mode 100644 includes/debug/logger/NullSpi.php create mode 100644 includes/debug/logger/Spi.php create mode 100644 includes/debug/logger/monolog/Handler.php create mode 100644 includes/debug/logger/monolog/Processor.php create mode 100644 includes/debug/logger/monolog/Spi.php diff --git a/docs/mwlogger.txt b/docs/mwlogger.txt new file mode 100644 index 0000000000..9964e8b671 --- /dev/null +++ b/docs/mwlogger.txt @@ -0,0 +1,59 @@ +MWLogger implements a PSR-3 [0] compatible message logging system. + +The MWLogger class is actually a thin wrapper around any PSR-3 LoggerInterface +implementation. Named MWLogger instances can be obtained from the +MWLogger::getInstance() static method. MWLogger expects a class implementing +the MWLoggerSpi interface to act as a factory for new MWLogger instances. + +The "Spi" in MWLoggerSpi stands for "service provider interface". An SPI is +a API intended to be implemented or extended by a third party. This software +design pattern is intended to enable framework extension and replaceable +components. It is specifically used in the MWLogger service to allow alternate +PSR-3 logging implementations to be easily integrated with MediaWiki. + +The MWLogger::getInstance() static method is the means by which most code +acquires an MWLogger instance. This in turn delegates creation of MWLogger +instances to a class implementing the MWLoggerSpi service provider interface. + +The service provider interface allows the backend logging library to be +implemented in multiple ways. The $wgMWLoggerDefaultSpi global provides the +classname of the default MWLoggerSpi implementation to be loaded at runtime. +This can either be the name of a class implementing the MWLoggerSpi with +a zero argument constructor or a callable that will return an MWLoggerSpi +instance. Alternately the MWLogger::registerProvider method can be called +to inject an MWLoggerSpi instance into MWLogger and bypass the use of this +configuration variable. + +The MWLoggerMonologSpi class implements a service provider to generate +MWLogger instances that use the Monolog [1] logging library. See the PHP docs +(or source) for MWLoggerMonologSpi for details on the configuration of this +provider. The default configuration installs a null handler that will silently +discard all logging events. The documentation provided by the class describes +a more feature rich logging configuration. + +== Classes == +; MWLogger +: PSR-3 compatible logger that wraps any \Psr\Log\LoggerInterface + implementation +; MWLoggerSpi +: Service provider interface for MWLogger factories +; MWLoggerNullSpi +: MWLoggerSpi for creating instances that discard all log events +; MWLoggerMonologSpi +: MWLoggerSpi for creating instances backed by the monolog logging library +; MwLoggerMonologHandler +: Monolog handler that replicates the udp2log and file logging + functionality of wfErrorLog() +; MwLoggerMonologProcessor +: Monolog log processer that adds host: wfHostname() and wiki: wfWikiID() + to all records + +== Globals == +; $wgMWLoggerDefaultSpi +: Default service provider interface to use with MWLogger +; $wgMWLoggerMonologSpiConfig +: Configuration for MWLoggerMonologSpi describing how to configure the + Monolog logger instances. + +[0]: https://github.com/php-fig/fig-standards/blob/master/accepted/PSR-3-logger-interface.md +[1]: https://github.com/Seldaek/monolog diff --git a/includes/AutoLoader.php b/includes/AutoLoader.php index 2a45fc35fa..84715dba5e 100644 --- a/includes/AutoLoader.php +++ b/includes/AutoLoader.php @@ -461,6 +461,12 @@ $wgAutoloadLocalClasses = array( # includes/debug 'MWDebug' => 'includes/debug/MWDebug.php', + 'MWLogger' => 'includes/debug/logger/Logger.php', + 'MWLoggerMonologHandler' => 'includes/debug/logger/monolog/Handler.php', + 'MWLoggerMonologProcessor' => 'includes/debug/logger/monolog/Processor.php', + 'MWLoggerMonologSpi' => 'includes/debug/logger/monolog/Spi.php', + 'MWLoggerNullSpi' => 'includes/debug/logger/NullSpi.php', + 'MWLoggerSpi' => 'includes/debug/logger/Spi.php', # includes/deferred 'DataUpdate' => 'includes/deferred/DataUpdate.php', diff --git a/includes/DefaultSettings.php b/includes/DefaultSettings.php index f2453e842a..a684bc305e 100644 --- a/includes/DefaultSettings.php +++ b/includes/DefaultSettings.php @@ -5223,6 +5223,43 @@ $wgDebugDumpSqlLength = 500; */ $wgDebugLogGroups = array(); +/** + * Default service provider for creating MWLogger instances. + * + * This can either be the name of a class implementing the MWLoggerSpi + * interface with a zero argument constructor or a callable that will return + * an MWLoggerSpi instance. Alternately the MWLogger::registerProvider method + * can be called to inject an MWLoggerSpi instance into MWLogger and bypass + * the use of this configuration variable. + * + * @since 1.25 + * @var $wgMWLoggerDefaultSpi string|callable + * @see MwLogger + */ +$wgMWLoggerDefaultSpi = 'MWLoggerNullSpi'; + +/** + * Configuration for MWLoggerMonologSpi logger factory. + * + * Default configuration installs a null handler that will silently discard + * all logging events. + * + * @since 1.25 + * @see MWLoggerMonologSpi + */ +$wgMWLoggerMonologSpiConfig = array( + 'loggers' => array( + '@default' => array( + 'handlers' => array( 'null' ), + ), + ), + 'handlers' => array( + 'null' => array( + 'class' => '\\Monolog\\Logger\\NullHandler', + ), + ), +); + /** * Display debug data at the bottom of the main content area. * diff --git a/includes/debug/logger/Logger.php b/includes/debug/logger/Logger.php new file mode 100644 index 0000000000..f5dd1cf7c2 --- /dev/null +++ b/includes/debug/logger/Logger.php @@ -0,0 +1,212 @@ + + * @copyright © 2014 Bryan Davis and Wikimedia Foundation. + */ +class MWLogger implements \Psr\Log\LoggerInterface { + + /** + * Service provider. + * @var MWLoggerSpi $spi + */ + protected static $spi; + + + /** + * Wrapped PSR-3 logger instance. + * + * @var \Psr\Log\LoggerInterface $delegate + */ + protected $delegate; + + + /** + * @param \Psr\Log\LoggerInterface $logger + */ + public function __construct( \Psr\Log\LoggerInterface $logger ) { + $this->delegate = $logger; + } + + + /** + * Logs with an arbitrary level. + * + * @param string|int $level + * @param string $message + * @param array $context + */ + public function log( $level, $message, array $context = array() ) { + $this->delegate->log( $level, $message, $context ); + } + + + /** + * System is unusable. + * + * @param string $message + * @param array $context + */ + public function emergency( $message, array $context = array() ) { + $this->log( \Psr\Log\LogLevel::EMERGENCY, $message, $context ); + } + + + /** + * Action must be taken immediately. + * + * Example: Entire website down, database unavailable, etc. This should + * trigger the SMS alerts and wake you up. + * + * @param string $message + * @param array $context + */ + public function alert( $message, array $context = array() ) { + $this->log( \Psr\Log\LogLevel::ALERT, $message, $context ); + } + + + /** + * Critical conditions. + * + * Example: Application component unavailable, unexpected exception. + * + * @param string $message + * @param array $context + */ + public function critical( $message, array $context = array( ) ) { + $this->log( \Psr\Log\LogLevel::CRITICAL, $message, $context ); + } + + + /** + * Runtime errors that do not require immediate action but should typically + * be logged and monitored. + * + * @param string $message + * @param array $context + */ + public function error( $message, array $context = array( ) ) { + $this->log( \Psr\Log\LogLevel::ERROR, $message, $context ); + } + + + /** + * Exceptional occurrences that are not errors. + * + * Example: Use of deprecated APIs, poor use of an API, undesirable things + * that are not necessarily wrong. + * + * @param string $message + * @param array $context + */ + public function warning( $message, array $context = array() ) { + $this->log( \Psr\Log\LogLevel::WARNING, $message, $context ); + } + + + /** + * Normal but significant events. + * + * @param string $message + * @param array $context + */ + public function notice( $message, array $context = array() ) { + $this->log( \Psr\Log\LogLevel::NOTICE, $message, $context ); + } + + + /** + * Interesting events. + * + * Example: User logs in, SQL logs. + * + * @param string $message + * @param array $context + */ + public function info( $message, array $context = array() ) { + $this->log( \Psr\Log\LogLevel::INFO, $message, $context ); + } + + + /** + * Detailed debug information. + * + * @param string $message + * @param array $context + */ + public function debug( $message, array $context = array() ) { + $this->log( \Psr\Log\LogLevel::DEBUG, $message, $context ); + } + + + /** + * Register a service provider to create new MWLogger instances. + * + * @param MWLoggerSpi $provider Provider to register + */ + public static function registerProvider( MWLoggerSpi $provider ) { + self::$spi = $provider; + } + + + /** + * Get a named logger instance from the currently configured logger factory. + * + * @param string $channel Logger channel (name) + * @return MWLogger + */ + public static function getInstance( $channel ) { + if ( self::$spi === null ) { + global $wgMWLoggerDefaultSpi; + if ( is_callable( $wgMWLoggerDefaultSpi ) ) { + $provider = $wgMWLoggerDefaultSpi(); + } else { + $provider = new $wgMWLoggerDefaultSpi(); + } + self::registerProvider( $provider ); + } + + return self::$spi->getLogger( $channel ); + } + +} diff --git a/includes/debug/logger/NullSpi.php b/includes/debug/logger/NullSpi.php new file mode 100644 index 0000000000..6c38c329ee --- /dev/null +++ b/includes/debug/logger/NullSpi.php @@ -0,0 +1,54 @@ + + * @copyright © 2014 Bryan Davis and Wikimedia Foundation. + */ +class MWLoggerNullSpi implements MWLoggerSpi { + + /** + * @var \Psr\Log\NullLogger $singleton + */ + protected $singleton; + + + public function __construct() { + $this->singleton = new \Psr\Log\NullLogger(); + } + + + /** + * Get a logger instance. + * + * @param string $channel Logging channel + * @return MWLogger Logger instance + */ + public function getLogger( $channel ) { + return $this->singleton; + } + +} diff --git a/includes/debug/logger/Spi.php b/includes/debug/logger/Spi.php new file mode 100644 index 0000000000..7139856453 --- /dev/null +++ b/includes/debug/logger/Spi.php @@ -0,0 +1,45 @@ + + * @copyright © 2014 Bryan Davis and Wikimedia Foundation. + */ +interface MWLoggerSpi { + + /** + * Get a logger instance. + * + * @param string $channel Logging channel + * @return MWLogger Logger instance + */ + public function getLogger( $channel ); + +} diff --git a/includes/debug/logger/monolog/Handler.php b/includes/debug/logger/monolog/Handler.php new file mode 100644 index 0000000000..1472459f02 --- /dev/null +++ b/includes/debug/logger/monolog/Handler.php @@ -0,0 +1,212 @@ + + * @copyright © 2013 Bryan Davis and Wikimedia Foundation. + */ +class MWLoggerMonologHandler extends \Monolog\Handler\AbstractProcessingHandler { + + /** + * Log sink descriptor + * @var string $uri + */ + protected $uri; + + /** + * Log sink + * @var resource $sink + */ + protected $sink; + + /** + * @var string $error + */ + protected $error; + + /** + * @var string $host + */ + protected $host; + + /** + * @var int $port + */ + protected $port; + + /** + * @var string $prefix + */ + protected $prefix; + + + /** + * @param string $stream Stream URI + * @param int $level Minimum logging level that will trigger handler + * @param bool $bubble Can handled meesages bubble up the handler stack? + */ + public function __construct( + $stream, $level = \Monolog\Logger::DEBUG, $bubble = true + ) { + parent::__construct( $level, $bubble ); + $this->uri = $stream; + } + + + /** + * Open the log sink described by our stream URI. + */ + protected function openSink() { + if ( !$this->uri ) { + throw new LogicException( + 'Missing stream uri, the stream can not be opened.' ); + } + $this->error = null; + set_error_handler( array( $this, 'errorTrap' ) ); + + if ( substr( $this->uri, 0, 4 ) == 'udp:' ) { + $parsed = parse_url( $this->uri ); + if ( !isset( $parsed['host'] ) ) { + throw new UnexpectedValueException( sprintf( + 'Udp transport "%s" must specify a host', $this->uri + ) ); + } + if ( !isset( $parsed['port'] ) ) { + throw new UnexpectedValueException( sprintf( + 'Udp transport "%s" must specify a port', $this->uri + ) ); + } + + $this->host = $parsed['host']; + $this->port = $parsed['port']; + $this->prefix = ''; + + if ( isset( $parsed['path'] ) ) { + $this->prefix = ltrim( $parsed['path'], '/' ); + } + + if ( filter_var( $this->host, FILTER_VALIDATE_IP, FILTER_FLAG_IPV6 ) ) { + $domain = AF_INET6; + + } else { + $domain = AF_INET; + } + + $this->sink = socket_create( $domain, SOCK_DGRAM, SOL_UDP ); + + } else { + $this->sink = fopen( $this->uri, 'a' ); + } + restore_error_handler(); + + if ( !is_resource( $this->sink ) ) { + $this->sink = null; + throw new UnexpectedValueException( sprintf( + 'The stream or file "%s" could not be opened: %s', + $this->uri, $this->error + ) ); + } + } + + + /** + * Custom error handler. + * @param int $code Error number + * @param string $msg Error message + */ + protected function errorTrap( $code, $msg ) { + $this->error = $msg; + } + + + /** + * Should we use UDP to send messages to the sink? + * @return bool + */ + protected function useUdp() { + return $this->host !== null; + } + + + protected function write( array $record ) { + if ( $this->sink === null ) { + $this->openSink(); + } + + $text = (string) $record['formatted']; + if ( $this->useUdp() ) { + + // Clean it up for the multiplexer + if ( $this->prefix !== '' ) { + $text = preg_replace( '/^/m', "{$this->prefix} ", $text ); + + // Limit to 64KB + if ( strlen( $text ) > 65506 ) { + $text = substr( $text, 0, 65506 ); + } + + if ( substr( $text, -1 ) != "\n" ) { + $text .= "\n"; + } + + } elseif ( strlen( $text ) > 65507 ) { + $text = substr( $text, 0, 65507 ); + } + + socket_sendto( + $this->sink, $text, strlen( $text ), 0, $this->host, $this->port ); + + } else { + fwrite( $this->sink, $text ); + } + } + + + public function close() { + if ( is_resource( $this->sink ) ) { + if ( $this->useUdp() ) { + socket_close( $this->sink ); + + } else { + fclose( $this->sink ); + } + } + $this->sink = null; + } + +} diff --git a/includes/debug/logger/monolog/Processor.php b/includes/debug/logger/monolog/Processor.php new file mode 100644 index 0000000000..a9f72c8f66 --- /dev/null +++ b/includes/debug/logger/monolog/Processor.php @@ -0,0 +1,47 @@ + + * @copyright © 2013 Bryan Davis and Wikimedia Foundation. + */ +class MWLoggerMonologProcessor { + + /** + * @param array $record + * @return array + */ + public function __invoke( array $record ) { + $record['extra'] = array_merge( + $record['extra'], + array( + 'host' => wfHostname(), + 'wiki' => wfWikiID(), + ) + ); + return $record; + } + +} diff --git a/includes/debug/logger/monolog/Spi.php b/includes/debug/logger/monolog/Spi.php new file mode 100644 index 0000000000..fc39b25bba --- /dev/null +++ b/includes/debug/logger/monolog/Spi.php @@ -0,0 +1,279 @@ + array( + * '@default' => array( + * 'processors' => array( 'wiki', 'psr', 'pid', 'uid', 'web' ), + * 'handlers' => array( 'stream' ), + * ), + * 'runJobs' => array( + * 'processors' => array( 'wiki', 'psr', 'pid' ), + * 'handlers' => array( 'stream' ), + * ) + * ), + * 'processors' => array( + * 'wiki' => array( + * 'class' => 'MWLoggerMonologProcessor', + * ), + * 'psr' => array( + * 'class' => '\\Monolog\\Processor\\PsrLogMessageProcessor', + * ), + * 'pid' => array( + * 'class' => '\\Monolog\\Processor\\ProcessIdProcessor', + * ), + * 'uid' => array( + * 'class' => '\\Monolog\\Processor\\UidProcessor', + * ), + * 'web' => array( + * 'class' => '\\Monolog\\Processor\\WebProcessor', + * ), + * ), + * 'handlers' => array( + * 'stream' => array( + * 'class' => '\\Monolog\\Handler\\StreamHandler', + * 'args' => array( 'path/to/your.log' ), + * 'formatter' => 'line', + * ), + * 'redis' => array( + * 'class' => '\\Monolog\\Handler\\RedisHandler', + * 'args' => array( function() { + * $redis = new Redis(); + * $redis->connect( '127.0.0.1', 6379 ); + * return $redis; + * }, + * 'logstash' + * ), + * 'formatter' => 'logstash', + * ), + * 'udp2log' => array( + * 'class' => 'MWLoggerMonologHandler', + * 'args' => array( + * 'udp://127.0.0.1:8420/mediawiki + * ), + * 'formatter' => 'line', + * ), + * ), + * 'formatters' => array( + * 'line' => array( + * 'class' => '\\Monolog\\Formatter\\LineFormatter', + * ), + * 'logstash' => array( + * 'class' => '\\Monolog\\Formatter\\LogstashFormatter', + * 'args' => array( 'mediawiki', php_uname( 'n' ), null, '', 1 ), + * ), + * ), + * ); + * @endcode + * + * @see https://github.com/Seldaek/monolog + * @since 1.25 + * @author Bryan Davis + * @copyright © 2014 Bryan Davis and Wikimedia Foundation. + */ +class MWLoggerMonologSpi implements MWLoggerSpi { + + /** + * @var array $singletons + */ + protected $singletons; + + /** + * Configuration for creating new loggers. + * @var array $config + */ + protected $config; + + + /** + * @param array $config Configuration data. Defaults to global + * $wgMWLoggerMonologSpiConfig + */ + public function __construct( $config = null ) { + if ( $config === null ) { + global $wgMWLoggerMonologSpiConfig; + $config = $wgMWLoggerMonologSpiConfig; + } + $this->config = $config; + $this->reset(); + } + + + /** + * Reset internal caches. + * + * This is public for use in unit tests. Under normal operation there should + * be no need to flush the caches. + */ + public function reset() { + $this->singletons = array( + 'loggers' => array(), + 'handlers' => array(), + 'formatters' => array(), + 'processors' => array(), + ); + } + + + /** + * Get a logger instance. + * + * Creates and caches a logger instance based on configuration found in the + * $wgMWLoggerMonologSpiConfig global. Subsequent request for the same channel + * name will return the cached instance. + * + * @param string $channel Logging channel + * @return MWLogger Logger instance + */ + public function getLogger( $channel ) { + if ( !isset( $this->singletons['loggers'][$channel] ) ) { + // Fallback to using the '@default' configuration if an explict + // configuration for the requested channel isn't found. + $spec = isset( $this->config['loggers'][$channel] ) ? + $this->config['loggers'][$channel] : + $this->config['loggers']['@default']; + + $monolog = $this->createLogger( $channel, $spec ); + $this->singletons['loggers'][$channel] = new MWLogger( $monolog ); + } + + return $this->singletons['loggers'][$channel]; + } + + + /** + * Create a logger. + * @param string $channel Logger channel + * @param array $spec Configuration + * @return \Monolog\Logger + */ + protected function createLogger( $channel, $spec ) { + $obj = new \Monolog\Logger( $channel ); + + if ( isset( $spec['processors'] ) ) { + foreach ( $spec['processors'] as $processor ) { + $obj->pushProcessor( $this->getProcessor( $processor ) ); + } + } + + if ( isset( $spec['handlers'] ) ) { + foreach ( $spec['handlers'] as $handler ) { + $obj->pushHandler( $this->getHandler( $handler ) ); + } + } + return $obj; + } + + + /** + * Create or return cached processor. + * @param string $name Processor name + * @return callable + */ + protected function getProcessor( $name ) { + if ( !isset( $this->singletons['processors'][$name] ) ) { + $spec = $this->config['processors'][$name]; + $this->singletons['processors'][$name] = $this->instantiate( $spec ); + } + return $this->singletons['processors'][$name]; + } + + + /** + * Create or return cached handler. + * @param string $name Processor name + * @return \Monolog\Handler\HandlerInterface + */ + protected function getHandler( $name ) { + if ( !isset( $this->singletons['handlers'][$name] ) ) { + $spec = $this->config['handlers'][$name]; + $handler = $this->instantiate( $spec ); + $handler->setFormatter( $this->getFormatter( $spec['formatter'] ) ); + $this->singletons['handlers'][$name] = $handler; + } + return $this->singletons['handlers'][$name]; + } + + + /** + * Create or return cached formatter. + * @param string $name Formatter name + * @return \Monolog\Formatter\FormatterInterface + */ + protected function getFormatter( $name ) { + if ( !isset( $this->singletons['formatters'][$name] ) ) { + $spec = $this->config['formatters'][$name]; + $this->singletons['formatters'][$name] = $this->instantiate( $spec ); + } + return $this->singletons['formatters'][$name]; + } + + + /** + * Instantiate the requested object. + * + * The specification array must contain a 'class' key with string value that + * specifies the class name to instantiate. It can optionally contain an + * 'args' key that provides constructor arguments. + * + * @param array $spec Object specification + * @return object + */ + protected function instantiate( $spec ) { + $clazz = $spec['class']; + $args = isset( $spec['args'] ) ? $spec['args'] : array(); + // If an argument is a callable, call it. + // This allows passing things such as a database connection to a logger. + $args = array_map( function ( $value ) { + if ( is_callable( $value ) ) { + return $value(); + } else { + return $value; + } + }, $args ); + + if ( empty( $args ) ) { + $obj = new $clazz(); + + } else { + $ref = new ReflectionClass( $clazz ); + $obj = $ref->newInstanceArgs( $args ); + } + + return $obj; + } + +} -- 2.20.1