From 81ba5376d0ef778ccad48d4869d43787f8dc9f09 Mon Sep 17 00:00:00 2001 From: Philipp Holzer Date: Sun, 3 Mar 2019 20:32:27 +0100 Subject: [PATCH] Added StreamLogger and ProfilerLogger --- config/defaults.config.php | 4 +- src/Factory/LoggerFactory.php | 74 +++++++--- src/Util/Logger/AbstractFriendicaLogger.php | 35 +---- src/Util/Logger/ProfilerLogger.php | 127 ++++++++++++++++ src/Util/Logger/REAMDE.md | 29 ++++ src/Util/Logger/StreamLogger.php | 154 +++++++++++++++++++- src/Util/Logger/SyslogLogger.php | 13 +- 7 files changed, 371 insertions(+), 65 deletions(-) create mode 100644 src/Util/Logger/ProfilerLogger.php create mode 100644 src/Util/Logger/REAMDE.md diff --git a/config/defaults.config.php b/config/defaults.config.php index 5ec4b62572..0d9e55c7d9 100644 --- a/config/defaults.config.php +++ b/config/defaults.config.php @@ -214,9 +214,9 @@ return [ // If activated, all hashtags will point to the local server. 'local_tags' => false, - // logger_adapter (String) + // logger_config (String) // Sets the logging adapter of Friendica globally (monolog, syslog, stream) - 'logger_adapter' => 'monolog', + 'logger_config' => 'stream', // max_batch_queue (Integer) // Maximum number of batched queue items for a single contact before subsequent messages are discarded. diff --git a/src/Factory/LoggerFactory.php b/src/Factory/LoggerFactory.php index 58efd461fe..0ab4c2ac20 100644 --- a/src/Factory/LoggerFactory.php +++ b/src/Factory/LoggerFactory.php @@ -8,6 +8,7 @@ use Friendica\Network\HTTPException\InternalServerErrorException; use Friendica\Util\Introspection; use Friendica\Util\Logger\Monolog\FriendicaDevelopHandler; use Friendica\Util\Logger\Monolog\FriendicaIntrospectionProcessor; +use Friendica\Util\Logger\ProfilerLogger; use Friendica\Util\Logger\StreamLogger; use Friendica\Util\Logger\SyslogLogger; use Friendica\Util\Logger\VoidLogger; @@ -57,18 +58,8 @@ class LoggerFactory $introspection = new Introspection(self::$ignoreClassList); $level = $config->get('system', 'loglevel'); - switch ($config->get('system', 'logger_adapter', 'monolog')) { - - case 'syslog': - $logger = new SyslogLogger($channel, $introspection, $profiler, $level); - break; - - case 'stream': - $logger = new StreamLogger($channel, $introspection, $profiler, $level); - break; - + switch ($config->get('system', 'logger_config', 'stream')) { case 'monolog': - default: $loggerTimeZone = new \DateTimeZone('UTC'); Monolog\Logger::setTimezone($loggerTimeZone); @@ -83,6 +74,23 @@ class LoggerFactory $loglevel = self::mapLegacyConfigDebugLevel((string)$level); static::addStreamHandler($logger, $stream, $loglevel); break; + + case 'syslog': + $logger = new SyslogLogger($channel, $introspection, $level); + break; + + case 'stream': + default: + $stream = $config->get('system', 'logfile'); + $logger = new StreamLogger($channel, $stream, $introspection, $level); + break; + } + + $profiling = $config->get('system', 'profiling', false); + + // In case profiling is enabled, wrap the ProfilerLogger around the current logger + if (isset($profiling) && $profiling !== false) { + $logger = new ProfilerLogger($logger, $profiler); } Logger::init($logger); @@ -100,18 +108,23 @@ class LoggerFactory * * @param string $channel The channel of the logger instance * @param Configuration $config The config + * @param Profiler $profiler The profiler of the app * * @return LoggerInterface The PSR-3 compliant logger instance + * * @throws InternalServerErrorException + * @throws \Exception */ - public static function createDev($channel, Configuration $config) + public static function createDev($channel, Configuration $config, Profiler $profiler) { $debugging = $config->get('system', 'debugging'); $stream = $config->get('system', 'dlogfile'); $developerIp = $config->get('system', 'dlogip'); if (!isset($developerIp) || !$debugging) { - return null; + $logger = new VoidLogger(); + Logger::setDevLogger($logger); + return $logger; } $loggerTimeZone = new \DateTimeZone('UTC'); @@ -119,15 +132,36 @@ class LoggerFactory $introspection = new Introspection(self::$ignoreClassList); - $logger = new Monolog\Logger($channel); - $logger->pushProcessor(new Monolog\Processor\PsrLogMessageProcessor()); - $logger->pushProcessor(new Monolog\Processor\ProcessIdProcessor()); - $logger->pushProcessor(new Monolog\Processor\UidProcessor()); - $logger->pushProcessor(new FriendicaIntrospectionProcessor($introspection, LogLevel::DEBUG)); + switch ($config->get('system', 'logger_config', 'stream')) { - $logger->pushHandler(new FriendicaDevelopHandler($developerIp)); + case 'monolog': + $logger = new Monolog\Logger($channel); + $logger->pushProcessor(new Monolog\Processor\PsrLogMessageProcessor()); + $logger->pushProcessor(new Monolog\Processor\ProcessIdProcessor()); + $logger->pushProcessor(new Monolog\Processor\UidProcessor()); + $logger->pushProcessor(new FriendicaIntrospectionProcessor($introspection, LogLevel::DEBUG)); - static::addStreamHandler($logger, $stream, LogLevel::DEBUG); + $logger->pushHandler(new FriendicaDevelopHandler($developerIp)); + + static::addStreamHandler($logger, $stream, LogLevel::DEBUG); + break; + + case 'syslog': + $logger = new SyslogLogger($channel, $introspection, LogLevel::DEBUG); + break; + + case 'stream': + default: + $logger = new StreamLogger($channel, $stream, $introspection, LogLevel::DEBUG); + break; + } + + $profiling = $config->get('system', 'profiling', false); + + // In case profiling is enabled, wrap the ProfilerLogger around the current logger + if (isset($profiling) && $profiling !== false) { + $logger = new ProfilerLogger($logger, $profiler); + } Logger::setDevLogger($logger); diff --git a/src/Util/Logger/AbstractFriendicaLogger.php b/src/Util/Logger/AbstractFriendicaLogger.php index 326ee05004..82f2f56c53 100644 --- a/src/Util/Logger/AbstractFriendicaLogger.php +++ b/src/Util/Logger/AbstractFriendicaLogger.php @@ -2,9 +2,7 @@ namespace Friendica\Util\Logger; -use Friendica\Core\System; use Friendica\Util\Introspection; -use Friendica\Util\Profiler; use Friendica\Util\Strings; use Psr\Log\LoggerInterface; use Psr\Log\LogLevel; @@ -13,9 +11,10 @@ use Psr\Log\LogLevel; * This class contains all necessary dependencies and calls for Friendica * Every new Logger should extend this class and define, how addEntry() works * - * Contains: + * Additional information for each Logger, who extends this class: * - Introspection - * - Automatic Friendica profiling + * - UID for each call + * - Channel of the current call (i.e. index, worker, daemon, ...) */ abstract class AbstractFriendicaLogger implements LoggerInterface { @@ -31,12 +30,6 @@ abstract class AbstractFriendicaLogger implements LoggerInterface */ protected $introspection; - /** - * The Profiler for the current call - * @var Profiler - */ - protected $profiler; - /** * The UID of the current call * @var string @@ -57,15 +50,13 @@ abstract class AbstractFriendicaLogger implements LoggerInterface /** * @param string $channel The output channel * @param Introspection $introspection The introspection of the current call - * @param Profiler $profiler The profiler of the current call * * @throws \Exception */ - public function __construct($channel, Introspection $introspection, Profiler $profiler) + public function __construct($channel, Introspection $introspection) { $this->channel = $channel; $this->introspection = $introspection; - $this->profiler = $profiler; $this->logUid = Strings::getRandomHex(6); } @@ -98,9 +89,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface */ public function emergency($message, array $context = array()) { - $stamp1 = microtime(true); $this->addEntry(LogLevel::EMERGENCY, (string) $message, $context); - $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -108,9 +97,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface */ public function alert($message, array $context = array()) { - $stamp1 = microtime(true); $this->addEntry(LogLevel::ALERT, (string) $message, $context); - $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -118,9 +105,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface */ public function critical($message, array $context = array()) { - $stamp1 = microtime(true); $this->addEntry(LogLevel::CRITICAL, (string) $message, $context); - $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -128,9 +113,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface */ public function error($message, array $context = array()) { - $stamp1 = microtime(true); $this->addEntry(LogLevel::ERROR, (string) $message, $context); - $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -138,9 +121,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface */ public function warning($message, array $context = array()) { - $stamp1 = microtime(true); $this->addEntry(LogLevel::WARNING, (string) $message, $context); - $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -148,9 +129,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface */ public function notice($message, array $context = array()) { - $stamp1 = microtime(true); $this->addEntry(LogLevel::NOTICE, (string) $message, $context); - $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -158,9 +137,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface */ public function info($message, array $context = array()) { - $stamp1 = microtime(true); $this->addEntry(LogLevel::INFO, (string) $message, $context); - $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -168,9 +145,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface */ public function debug($message, array $context = array()) { - $stamp1 = microtime(true); $this->addEntry(LogLevel::DEBUG, (string) $message, $context); - $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -178,8 +153,6 @@ abstract class AbstractFriendicaLogger implements LoggerInterface */ public function log($level, $message, array $context = array()) { - $stamp1 = microtime(true); $this->addEntry($level, (string) $message, $context); - $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } } diff --git a/src/Util/Logger/ProfilerLogger.php b/src/Util/Logger/ProfilerLogger.php new file mode 100644 index 0000000000..fdb7c52b2a --- /dev/null +++ b/src/Util/Logger/ProfilerLogger.php @@ -0,0 +1,127 @@ +logger = $logger; + $this->profiler = $profiler; + } + + /** + * {@inheritdoc} + */ + public function emergency($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->logger->emergency($message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function alert($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->logger->alert($message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function critical($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->logger->critical($message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function error($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->logger->error($message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function warning($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->logger->warning($message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function notice($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->logger->notice($message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function info($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->logger->info($message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function debug($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->logger->debug($message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function log($level, $message, array $context = array()) + { + $stamp1 = microtime(true); + $this->logger->log($level, $message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } +} diff --git a/src/Util/Logger/REAMDE.md b/src/Util/Logger/REAMDE.md new file mode 100644 index 0000000000..381bd94ba7 --- /dev/null +++ b/src/Util/Logger/REAMDE.md @@ -0,0 +1,29 @@ +## Friendica\Util\Logger + +This namespace contains the different implementations of a Logger. + +### Configuration guideline + +The following settings are possible for `logger_config`: +- `monolog`: A Logging framework with lots of additions (see [Monolog](https://github.com/Seldaek/monolog/)). There are just Friendica additions inside the Monolog directory +- [`stream`](StreamLogger.php): A small logger for files or streams +- [`syslog`](SyslogLogger.php): Prints the logging output into the syslog + +[`VoidLogger`](VoidLogger.php) is a fallback logger without any function if no debugging is enabled. + +[`ProfilerLogger`](ProfilerLogger.php) is a wrapper around an existing logger in case profiling is enabled for Friendica. +Every log call will be saved to the `Profiler` with a timestamp. + +### Implementation guideline + +Each logging implementation should pe capable of printing at least the following information: +- An unique ID for each Request/Call +- The process ID (PID) +- A timestamp of the logging entry +- The critically of the log entry +- A log message +- A context of the log message (f.e which user) + +If possible, a Logger should extend [`AbstractFriendicaLogger`](AbstractFriendicaLogger.php), because it contains additional, Friendica specific business logic for each logging call. + +Using AbstractFriendicaLogger makes the logger capable of adding profiling data for each log call. diff --git a/src/Util/Logger/StreamLogger.php b/src/Util/Logger/StreamLogger.php index 8d9ffec387..ad1b152d9e 100644 --- a/src/Util/Logger/StreamLogger.php +++ b/src/Util/Logger/StreamLogger.php @@ -2,8 +2,9 @@ namespace Friendica\Util\Logger; +use Friendica\Util\DateTimeFormat; use Friendica\Util\Introspection; -use Friendica\Util\Profiler; +use Psr\Log\LogLevel; /** * A Logger instance for logging into a stream (file, stdout, stderr) @@ -16,10 +17,73 @@ class StreamLogger extends AbstractFriendicaLogger */ private $logLevel; - public function __construct($channel, Introspection $introspection, Profiler $profiler, $level) + /** + * The file URL of the stream (if needed) + * @var string + */ + private $url; + + /** + * The stream, where the current logger is writing into + * @var resource + */ + private $stream; + + /** + * The current process ID + * @var int + */ + private $pid; + + /** + * Translates LogLevel log levels to integer values + * @var array + */ + private $levelToInt = [ + LogLevel::EMERGENCY => 0, + LogLevel::ALERT => 1, + LogLevel::CRITICAL => 2, + LogLevel::ERROR => 3, + LogLevel::WARNING => 4, + LogLevel::NOTICE => 5, + LogLevel::INFO => 6, + LogLevel::DEBUG => 7, + ]; + + /** + * {@inheritdoc} + * @param string|resource $stream The stream to write with this logger (either a file or a stream, i.e. stdout) + * @param string $level The minimum loglevel at which this logger will be triggered + * + * @throws \Exception + */ + public function __construct($channel, $stream, Introspection $introspection, $level = LogLevel::DEBUG) { - parent::__construct($channel, $introspection, $profiler); - $this->logLevel = $level; + parent::__construct($channel, $introspection); + + if (is_resource($stream)) { + $this->stream = $stream; + } elseif (is_string($stream)) { + $this->url = $stream; + } else { + throw new \InvalidArgumentException('A stream must either be a resource or a string.'); + } + + $this->pid = getmypid(); + if (array_key_exists($level, $this->levelToInt)) { + $this->logLevel = $this->levelToInt[$level]; + } else { + throw new \InvalidArgumentException(sprintf('The level "%s" is not valid.', $level)); + } + } + + public function close() + { + if ($this->url && is_resource($this->stream)) { + fclose($this->stream); + } + + $this->stream = null; } /** @@ -33,6 +97,86 @@ class StreamLogger extends AbstractFriendicaLogger */ protected function addEntry($level, $message, $context = []) { - // TODO: Implement addEntry() method. + if (!array_key_exists($level, $this->levelToInt)) { + throw new \InvalidArgumentException('The level "%s" is not valid', $level); + } + + $logLevel = $this->levelToInt[$level]; + + if ($logLevel > $this->logLevel) { + return; + } + + $this->checkStream(); + + $this->stream = fopen($this->url, 'a'); + $formattedLog = $this->formatLog($level, $message, $context); + fwrite($this->stream, $formattedLog); + } + + /** + * Formats a log record for the syslog output + * + * @param int $level The loglevel/priority + * @param string $message The message + * @param array $context The context of this call + * + * @return string the formatted syslog output + */ + private function formatLog($level, $message, $context = []) + { + $record = $this->introspection->getRecord(); + $record = array_merge($record, ['uid' => $this->logUid, 'process_id' => $this->pid]); + $logMessage = ''; + + $logMessage .= DateTimeFormat::localNow() . ' '; + $logMessage .= $this->channel . ' '; + $logMessage .= '[' . strtoupper($level) . ']: '; + $logMessage .= $this->psrInterpolate($message, $context) . ' '; + $logMessage .= @json_encode($context) . ' - '; + $logMessage .= @json_encode($record); + $logMessage .= PHP_EOL; + + return $logMessage; + } + + private function checkStream() + { + if (is_resource($this->stream)) { + return; + } + + if (empty($this->url)) { + throw new \LogicException('Missing stream URL.'); + } + + $this->createDir(); + $this->stream = fopen($this->url, 'a'); + + if (!is_resource($this->stream)) { + $this->stream = null; + + throw new \UnexpectedValueException(sprintf('The stream or file "%s" could not be opened.', $this->url)); + } + } + + private function createDir() + { + $dirname = null; + $pos = strpos($this->url, '://'); + if (!$pos) { + $dirname = dirname($this->url); + } + + if (substr($this->url, 0, 7) === 'file://') { + $dirname = dirname(substr($this->url, 7)); + } + + if (isset($dirname) && !is_dir($dirname)) { + $status = mkdir($dirname, 0777, true); + if (!$status && !is_dir($dirname)) { + throw new \UnexpectedValueException(sprintf('Directory "%s" cannot get created.', $dirname)); + } + } } } diff --git a/src/Util/Logger/SyslogLogger.php b/src/Util/Logger/SyslogLogger.php index cff7125e5b..2d4a5fe311 100644 --- a/src/Util/Logger/SyslogLogger.php +++ b/src/Util/Logger/SyslogLogger.php @@ -4,7 +4,6 @@ namespace Friendica\Util\Logger; use Friendica\Network\HTTPException\InternalServerErrorException; use Friendica\Util\Introspection; -use Friendica\Util\Profiler; use Psr\Log\InvalidArgumentException; use Psr\Log\LogLevel; @@ -70,15 +69,15 @@ class SyslogLogger extends AbstractFriendicaLogger /** * {@inheritdoc} - * @param string $level The minimum loglevel at which this logger will be triggered - * @param int $logOpts Indicates what logging options will be used when generating a log message - * @param int $logFacility Used to specify what type of program is logging the message + * @param string $level The minimum loglevel at which this logger will be triggered + * @param int $logOpts Indicates what logging options will be used when generating a log message + * @param int $logFacility Used to specify what type of program is logging the message * * @throws \Exception */ - public function __construct($channel, Introspection $introspection, Profiler $profiler, $level = LogLevel::NOTICE, $logOpts = LOG_PID, $logFacility = LOG_USER) + public function __construct($channel, Introspection $introspection, $level = LogLevel::NOTICE, $logOpts = LOG_PID, $logFacility = LOG_USER) { - parent::__construct($channel, $introspection, $profiler); + parent::__construct($channel, $introspection); $this->logOpts = $logOpts; $this->logFacility = $logFacility; $this->logLevel = $this->mapLevelToPriority($level); @@ -98,7 +97,7 @@ class SyslogLogger extends AbstractFriendicaLogger { $logLevel = $this->mapLevelToPriority($level); - if ($logLevel >= $this->logLevel) { + if ($logLevel > $this->logLevel) { return; }