From 45a1d1368ae657e52f85053f0955553c814a9b74 Mon Sep 17 00:00:00 2001 From: Philipp Holzer Date: Thu, 28 Feb 2019 08:56:28 +0100 Subject: [PATCH 1/9] Refactored Logging environment (cleaned up) --- src/Factory/LoggerFactory.php | 22 +- src/Util/{Logger => }/Introspection.php | 44 +-- .../{ => Monolog}/FriendicaDevelopHandler.php | 2 +- .../FriendicaIntrospectionProcessor.php | 43 +++ src/Util/Logger/StreamLogger.php | 301 ++++++++++++++++++ src/Util/Logger/SyslogLogger.php | 14 +- 6 files changed, 382 insertions(+), 44 deletions(-) rename src/Util/{Logger => }/Introspection.php (54%) rename src/Util/Logger/{ => Monolog}/FriendicaDevelopHandler.php (97%) create mode 100644 src/Util/Logger/Monolog/FriendicaIntrospectionProcessor.php create mode 100644 src/Util/Logger/StreamLogger.php diff --git a/src/Factory/LoggerFactory.php b/src/Factory/LoggerFactory.php index d36cebdb60..c337e01f59 100644 --- a/src/Factory/LoggerFactory.php +++ b/src/Factory/LoggerFactory.php @@ -5,8 +5,9 @@ namespace Friendica\Factory; use Friendica\Core\Config\Configuration; use Friendica\Core\Logger; use Friendica\Network\HTTPException\InternalServerErrorException; -use Friendica\Util\Logger\FriendicaDevelopHandler; -use Friendica\Util\Logger\Introspection; +use Friendica\Util\Introspection; +use Friendica\Util\Logger\Monolog\FriendicaDevelopHandler; +use Friendica\Util\Logger\Monolog\FriendicaIntrospectionProcessor; use Friendica\Util\Logger\SyslogLogger; use Friendica\Util\Logger\VoidLogger; use Friendica\Util\Profiler; @@ -24,10 +25,12 @@ class LoggerFactory /** * Creates a new PSR-3 compliant logger instances * - * @param string $channel The channel of the logger instance - * @param Configuration $config The config + * @param string $channel The channel of the logger instance + * @param Configuration $config The config * * @return LoggerInterface The PSR-3 compliant logger instance + * + * @throws \Exception */ public static function create($channel, Configuration $config) { @@ -37,12 +40,13 @@ class LoggerFactory return $logger; } + $introspection = new Introspection([Logger::class, SyslogLogger::class, Profiler::class]); + switch ($config->get('system', 'logger_adapter', 'monolog')) { case 'syslog': - $intorspector = new Introspection(LOG_DEBUG, [Logger::class, SyslogLogger::class, Profiler::class]); $level = $config->get('system', 'loglevel'); - $logger = new SyslogLogger($channel, $intorspector, $level); + $logger = new SyslogLogger($channel, $introspection, $level); break; case 'monolog': default: @@ -50,7 +54,7 @@ class LoggerFactory $logger->pushProcessor(new Monolog\Processor\PsrLogMessageProcessor()); $logger->pushProcessor(new Monolog\Processor\ProcessIdProcessor()); $logger->pushProcessor(new Monolog\Processor\UidProcessor()); - $logger->pushProcessor(new Introspection(LogLevel::DEBUG, [Logger::class, Profiler::class])); + $logger->pushProcessor(new FriendicaIntrospectionProcessor($introspection, LogLevel::DEBUG)); $stream = $config->get('system', 'logfile'); $level = $config->get('system', 'loglevel'); @@ -88,11 +92,13 @@ class LoggerFactory return null; } + $introspection = new Introspection([Logger::class, SyslogLogger::class, Profiler::class]); + $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 Introspection(LogLevel::DEBUG, ['Friendica\\Core\\Logger'])); + $logger->pushProcessor(new FriendicaIntrospectionProcessor($introspection, LogLevel::DEBUG)); $logger->pushHandler(new FriendicaDevelopHandler($developerIp)); diff --git a/src/Util/Logger/Introspection.php b/src/Util/Introspection.php similarity index 54% rename from src/Util/Logger/Introspection.php rename to src/Util/Introspection.php index f99225f9a2..aa8dce446c 100644 --- a/src/Util/Logger/Introspection.php +++ b/src/Util/Introspection.php @@ -1,20 +1,12 @@ level = Logger::toMonologLevel($level); - $this->skipClassesPartials = array_merge(array('Monolog\\'), $skipClassesPartials); + $this->skipClassesPartials = $skipClassesPartials; $this->skipStackFramesCount = $skipStackFramesCount; } - public function __invoke(array $record) + /** + * Adds new classes to get skipped + * @param array $classNames + */ + public function addClasses(array $classNames) { - // return if the level is not high enough - if ($record['level'] < $this->level) { - return $record; - } - // we should have the call source now - $record['extra'] = array_merge( - $record['extra'], - $this->getRecord() - ); - - return $record; + $this->skipClassesPartials = array_merge($this->skipClassesPartials, $classNames); } /** @@ -79,7 +63,7 @@ class Introspection implements ProcessorInterface * Checks if the current trace class or function has to be skipped * * @param array $trace The current trace array - * @param int $index The index of the current hierarchy level + * @param int $index The index of the current hierarchy level * @return bool True if the class or function should get skipped, otherwise false */ private function isTraceClassOrSkippedFunction(array $trace, $index) diff --git a/src/Util/Logger/FriendicaDevelopHandler.php b/src/Util/Logger/Monolog/FriendicaDevelopHandler.php similarity index 97% rename from src/Util/Logger/FriendicaDevelopHandler.php rename to src/Util/Logger/Monolog/FriendicaDevelopHandler.php index 908d7052cc..13a4645357 100644 --- a/src/Util/Logger/FriendicaDevelopHandler.php +++ b/src/Util/Logger/Monolog/FriendicaDevelopHandler.php @@ -1,6 +1,6 @@ level = Logger::toMonologLevel($level); + $introspection->addClasses(array('Monolog\\')); + $this->introspection = $introspection; + } + + public function __invoke(array $record) + { + // return if the level is not high enough + if ($record['level'] < $this->level) { + return $record; + } + // we should have the call source now + $record['extra'] = array_merge( + $record['extra'], + $this->introspection->getRecord() + ); + + return $record; + } +} diff --git a/src/Util/Logger/StreamLogger.php b/src/Util/Logger/StreamLogger.php new file mode 100644 index 0000000000..7b9bbb3c1b --- /dev/null +++ b/src/Util/Logger/StreamLogger.php @@ -0,0 +1,301 @@ + LOG_DEBUG, + LogLevel::INFO => LOG_INFO, + LogLevel::NOTICE => LOG_NOTICE, + LogLevel::WARNING => LOG_WARNING, + LogLevel::ERROR => LOG_ERR, + LogLevel::CRITICAL => LOG_CRIT, + LogLevel::ALERT => LOG_ALERT, + LogLevel::EMERGENCY => LOG_EMERG, + ]; + + /** + * Translates log priorities to string outputs + * @var array + */ + private $logToString = [ + LOG_DEBUG => 'DEBUG', + LOG_INFO => 'INFO', + LOG_NOTICE => 'NOTICE', + LOG_WARNING => 'WARNING', + LOG_ERR => 'ERROR', + LOG_CRIT => 'CRITICAL', + LOG_ALERT => 'ALERT', + LOG_EMERG => 'EMERGENCY' + ]; + + /** + * The channel of the current process (added to each message) + * @var string + */ + private $channel; + + /** + * Indicates what logging options will be used when generating a log message + * @see http://php.net/manual/en/function.openlog.php#refsect1-function.openlog-parameters + * + * @var int + */ + private $logOpts; + + /** + * Used to specify what type of program is logging the message + * @see http://php.net/manual/en/function.openlog.php#refsect1-function.openlog-parameters + * + * @var int + */ + private $logFacility; + + /** + * The minimum loglevel at which this logger will be triggered + * @var int + */ + private $logLevel; + + /** + * The Introspection for the current call + * @var Introspection + */ + private $introspection; + + /** + * The UID of the current call + * @var string + */ + private $logUid; + + /** + * @param string $channel The output channel + * @param Introspection $introspection The introspection of the current call + * @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, $level = LogLevel::NOTICE, $logOpts = LOG_PID, $logFacility = LOG_USER) + { + $this->logUid = Strings::getRandomHex(6); + $this->channel = $channel; + $this->logOpts = $logOpts; + $this->logFacility = $logFacility; + $this->logLevel = $this->mapLevelToPriority($level); + $this->introspection = $introspection; + } + + /** + * Maps the LogLevel (@see LogLevel ) to a SysLog priority (@see http://php.net/manual/en/function.syslog.php#refsect1-function.syslog-parameters ) + * + * @param string $level A LogLevel + * + * @return int The SysLog priority + * + * @throws \Psr\Log\InvalidArgumentException If the loglevel isn't valid + */ + public function mapLevelToPriority($level) + { + if (!array_key_exists($level, $this->logLevels)) { + throw new InvalidArgumentException('LogLevel \'' . $level . '\' isn\'t valid.'); + } + + return $this->logLevels[$level]; + } + + /** + * Writes a message to the syslog + * @see http://php.net/manual/en/function.syslog.php#refsect1-function.syslog-parameters + * + * @param int $priority The Priority + * @param string $message The message of the log + * + * @throws InternalServerErrorException if syslog cannot be used + */ + private function write($priority, $message) + { + if (!openlog(self::IDENT, $this->logOpts, $this->logFacility)) { + throw new InternalServerErrorException('Can\'t open syslog for ident "' . $this->channel . '" and facility "' . $this->logFacility . '""'); + } + + syslog($priority, $message); + } + + /** + * Closes the Syslog + */ + public function close() + { + closelog(); + } + + /** + * 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]); + $logMessage = ''; + + $logMessage .= $this->channel . ' '; + $logMessage .= '[' . $this->logToString[$level] . ']: '; + $logMessage .= $this->psrInterpolate($message, $context) . ' '; + $logMessage .= @json_encode($context) . ' - '; + $logMessage .= @json_encode($record); + + return $logMessage; + } + + /** + * Simple interpolation of PSR-3 compliant replacements ( variables between '{' and '}' ) + * @see https://www.php-fig.org/psr/psr-3/#12-message + * + * @param string $message + * @param array $context + * + * @return string the interpolated message + */ + private function psrInterpolate($message, array $context = array()) + { + $replace = []; + foreach ($context as $key => $value) { + // check that the value can be casted to string + if (!is_array($value) && (!is_object($value) || method_exists($value, '__toString'))) { + $replace['{' . $key . '}'] = $value; + } elseif (is_array($value)) { + $replace['{' . $key . '}'] = @json_encode($value); + } + } + + return strtr($message, $replace); + } + + /** + * Adds a new entry to the syslog + * + * @param int $level + * @param string $message + * @param array $context + * + * @throws InternalServerErrorException if the syslog isn't available + */ + private function addEntry($level, $message, $context = []) + { + if ($level >= $this->logLevel) { + return; + } + + $formattedLog = $this->formatLog($level, $message, $context); + $this->write($level, $formattedLog); + } + + /** + * {@inheritdoc} + * @throws InternalServerErrorException if the syslog isn't available + */ + public function emergency($message, array $context = array()) + { + $this->addEntry(LOG_EMERG, $message, $context); + } + + /** + * {@inheritdoc} + * @throws InternalServerErrorException if the syslog isn't available + */ + public function alert($message, array $context = array()) + { + $this->addEntry(LOG_ALERT, $message, $context); + } + + /** + * {@inheritdoc} + * @throws InternalServerErrorException if the syslog isn't available + */ + public function critical($message, array $context = array()) + { + $this->addEntry(LOG_CRIT, $message, $context); + } + + /** + * {@inheritdoc} + * @throws InternalServerErrorException if the syslog isn't available + */ + public function error($message, array $context = array()) + { + $this->addEntry(LOG_ERR, $message, $context); + } + + /** + * {@inheritdoc} + * @throws InternalServerErrorException if the syslog isn't available + */ + public function warning($message, array $context = array()) + { + $this->addEntry(LOG_WARNING, $message, $context); + } + + /** + * {@inheritdoc} + * @throws InternalServerErrorException if the syslog isn't available + */ + public function notice($message, array $context = array()) + { + $this->addEntry(LOG_NOTICE, $message, $context); + } + + /** + * {@inheritdoc} + * @throws InternalServerErrorException if the syslog isn't available + */ + public function info($message, array $context = array()) + { + $this->addEntry(LOG_INFO, $message, $context); + } + + /** + * {@inheritdoc} + * @throws InternalServerErrorException if the syslog isn't available + */ + public function debug($message, array $context = array()) + { + $this->addEntry(LOG_DEBUG, $message, $context); + } + + /** + * {@inheritdoc} + * @throws InternalServerErrorException if the syslog isn't available + */ + public function log($level, $message, array $context = array()) + { + $logLevel = $this->mapLevelToPriority($level); + $this->addEntry($logLevel, $message, $context); + } +} diff --git a/src/Util/Logger/SyslogLogger.php b/src/Util/Logger/SyslogLogger.php index 19395157d2..5cb1f8c9e6 100644 --- a/src/Util/Logger/SyslogLogger.php +++ b/src/Util/Logger/SyslogLogger.php @@ -3,6 +3,7 @@ namespace Friendica\Util\Logger; use Friendica\Network\HTTPException\InternalServerErrorException; +use Friendica\Util\Introspection; use Friendica\Util\Strings; use Psr\Log\InvalidArgumentException; use Psr\Log\LoggerInterface; @@ -75,7 +76,7 @@ class SyslogLogger implements LoggerInterface private $logLevel; /** - * The Introspector for the current call + * The Introspection for the current call * @var Introspection */ private $introspection; @@ -87,10 +88,13 @@ class SyslogLogger implements LoggerInterface private $logUid; /** - * @param string $channel The output channel - * @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 $channel The output channel + * @param Introspection $introspection The introspection of the current call + * @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, $level = LogLevel::NOTICE, $logOpts = LOG_PID, $logFacility = LOG_USER) { From 57bfc75a0c2427b9486e7f75b7894679e1fe81af Mon Sep 17 00:00:00 2001 From: Philipp Holzer Date: Thu, 28 Feb 2019 09:41:31 +0100 Subject: [PATCH 2/9] Moving Profiling to class --- src/Core/Logger.php | 62 +---- src/Factory/DependencyFactory.php | 2 +- src/Factory/LoggerFactory.php | 7 +- src/Util/Logger/AbstractFriendicaLogger.php | 185 +++++++++++++ src/Util/Logger/StreamLogger.php | 290 +------------------- src/Util/Logger/SyslogLogger.php | 145 +--------- tests/include/ApiTest.php | 2 +- tests/src/Database/DBATest.php | 2 +- tests/src/Database/DBStructureTest.php | 2 +- 9 files changed, 215 insertions(+), 482 deletions(-) create mode 100644 src/Util/Logger/AbstractFriendicaLogger.php diff --git a/src/Core/Logger.php b/src/Core/Logger.php index 3cb22e1e47..fc2dde1dfe 100644 --- a/src/Core/Logger.php +++ b/src/Core/Logger.php @@ -4,14 +4,13 @@ */ namespace Friendica\Core; -use Friendica\BaseObject; use Psr\Log\LoggerInterface; use Psr\Log\LogLevel; /** * @brief Logger functions */ -class Logger extends BaseObject +class Logger { /** * @see Logger::error() @@ -96,13 +95,7 @@ class Logger extends BaseObject */ public static function emergency($message, $context = []) { - if (!isset(self::$logger)) { - return; - } - - $stamp1 = microtime(true); self::$logger->emergency($message, $context); - self::getApp()->GetProfiler()->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -120,13 +113,7 @@ class Logger extends BaseObject */ public static function alert($message, $context = []) { - if (!isset(self::$logger)) { - return; - } - - $stamp1 = microtime(true); self::$logger->alert($message, $context); - self::getApp()->getProfiler()->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -143,13 +130,7 @@ class Logger extends BaseObject */ public static function critical($message, $context = []) { - if (!isset(self::$logger)) { - return; - } - - $stamp1 = microtime(true); self::$logger->critical($message, $context); - self::getApp()->getProfiler()->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -165,14 +146,7 @@ class Logger extends BaseObject */ public static function error($message, $context = []) { - if (!isset(self::$logger)) { - echo "not set!?\n"; - return; - } - - $stamp1 = microtime(true); self::$logger->error($message, $context); - self::getApp()->getProfiler()->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -190,13 +164,7 @@ class Logger extends BaseObject */ public static function warning($message, $context = []) { - if (!isset(self::$logger)) { - return; - } - - $stamp1 = microtime(true); self::$logger->warning($message, $context); - self::getApp()->getProfiler()->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -211,13 +179,7 @@ class Logger extends BaseObject */ public static function notice($message, $context = []) { - if (!isset(self::$logger)) { - return; - } - - $stamp1 = microtime(true); self::$logger->notice($message, $context); - self::getApp()->getProfiler()->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -234,13 +196,7 @@ class Logger extends BaseObject */ public static function info($message, $context = []) { - if (!isset(self::$logger)) { - return; - } - - $stamp1 = microtime(true); self::$logger->info($message, $context); - self::getApp()->getProfiler()->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -255,13 +211,7 @@ class Logger extends BaseObject */ public static function debug($message, $context = []) { - if (!isset(self::$logger)) { - return; - } - - $stamp1 = microtime(true); self::$logger->debug($message, $context); - self::getApp()->getProfiler()->saveTimestamp($stamp1, 'file', System::callstack()); } /** @@ -275,13 +225,7 @@ class Logger extends BaseObject */ public static function log($msg, $level = LogLevel::INFO) { - if (!isset(self::$logger)) { - return; - } - - $stamp1 = microtime(true); self::$logger->log($level, $msg); - self::getApp()->getProfiler()->saveTimestamp($stamp1, "file", System::callstack()); } /** @@ -296,12 +240,10 @@ class Logger extends BaseObject */ public static function devLog($msg, $level = LogLevel::DEBUG) { - if (!isset(self::$logger)) { + if (!isset(self::$devLogger)) { return; } - $stamp1 = microtime(true); self::$devLogger->log($level, $msg); - self::getApp()->getProfiler()->saveTimestamp($stamp1, "file", System::callstack()); } } diff --git a/src/Factory/DependencyFactory.php b/src/Factory/DependencyFactory.php index acbf4bfaf7..9ada2bc5d8 100644 --- a/src/Factory/DependencyFactory.php +++ b/src/Factory/DependencyFactory.php @@ -30,7 +30,7 @@ class DependencyFactory $config = Factory\ConfigFactory::createConfig($configCache); // needed to call PConfig::init() Factory\ConfigFactory::createPConfig($configCache); - $logger = Factory\LoggerFactory::create($channel, $config); + $logger = Factory\LoggerFactory::create($channel, $config, $profiler); return new App($config, $logger, $profiler, $isBackend); } diff --git a/src/Factory/LoggerFactory.php b/src/Factory/LoggerFactory.php index c337e01f59..ce8d9f2c9c 100644 --- a/src/Factory/LoggerFactory.php +++ b/src/Factory/LoggerFactory.php @@ -27,12 +27,13 @@ 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 \Exception */ - public static function create($channel, Configuration $config) + public static function create($channel, Configuration $config, Profiler $profiler) { if(empty($config->get('system', 'debugging', false))) { $logger = new VoidLogger(); @@ -40,13 +41,13 @@ class LoggerFactory return $logger; } - $introspection = new Introspection([Logger::class, SyslogLogger::class, Profiler::class]); + $introspection = new Introspection([Logger::class, Profiler::class]); switch ($config->get('system', 'logger_adapter', 'monolog')) { case 'syslog': $level = $config->get('system', 'loglevel'); - $logger = new SyslogLogger($channel, $introspection, $level); + $logger = new SyslogLogger($channel, $introspection, $profiler, $level); break; case 'monolog': default: diff --git a/src/Util/Logger/AbstractFriendicaLogger.php b/src/Util/Logger/AbstractFriendicaLogger.php new file mode 100644 index 0000000000..3f851f42de --- /dev/null +++ b/src/Util/Logger/AbstractFriendicaLogger.php @@ -0,0 +1,185 @@ +channel = $channel; + $this->introspection = $introspection; + $this->profiler = $profiler; + $this->logUid = Strings::getRandomHex(6); + } + + /** + * Simple interpolation of PSR-3 compliant replacements ( variables between '{' and '}' ) + * @see https://www.php-fig.org/psr/psr-3/#12-message + * + * @param string $message + * @param array $context + * + * @return string the interpolated message + */ + protected function psrInterpolate($message, array $context = array()) + { + $replace = []; + foreach ($context as $key => $value) { + // check that the value can be casted to string + if (!is_array($value) && (!is_object($value) || method_exists($value, '__toString'))) { + $replace['{' . $key . '}'] = $value; + } elseif (is_array($value)) { + $replace['{' . $key . '}'] = @json_encode($value); + } + } + + return strtr($message, $replace); + } + + /** + * {@inheritdoc} + */ + public function emergency($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->addEntry(LogLevel::EMERGENCY, $message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function alert($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->addEntry(LogLevel::ALERT, $message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function critical($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->addEntry(LogLevel::CRITICAL, $message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function error($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->addEntry(LogLevel::ERROR, $message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function warning($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->addEntry(LogLevel::WARNING, $message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function notice($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->addEntry(LogLevel::NOTICE, $message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function info($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->addEntry(LogLevel::INFO, $message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function debug($message, array $context = array()) + { + $stamp1 = microtime(true); + $this->addEntry(LogLevel::DEBUG, $message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } + + /** + * {@inheritdoc} + */ + public function log($level, $message, array $context = array()) + { + $stamp1 = microtime(true); + $this->addEntry($level, $message, $context); + $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); + } +} diff --git a/src/Util/Logger/StreamLogger.php b/src/Util/Logger/StreamLogger.php index 7b9bbb3c1b..4ccbc8283b 100644 --- a/src/Util/Logger/StreamLogger.php +++ b/src/Util/Logger/StreamLogger.php @@ -2,300 +2,30 @@ namespace Friendica\Util\Logger; -use Friendica\Network\HTTPException\InternalServerErrorException; use Friendica\Util\Introspection; -use Friendica\Util\Strings; -use Psr\Log\InvalidArgumentException; -use Psr\Log\LoggerInterface; -use Psr\Log\LogLevel; +use Friendica\Util\Profiler; /** * A Logger instance for logging into a stream - * @see http://php.net/manual/en/function.syslog.php */ -class StreamLogger implements LoggerInterface +class StreamLogger extends AbstractFriendicaLogger { - const IDENT = 'Friendica'; - - /** - * Translates LogLevel log levels to syslog log priorities. - * @var array - */ - private $logLevels = [ - LogLevel::DEBUG => LOG_DEBUG, - LogLevel::INFO => LOG_INFO, - LogLevel::NOTICE => LOG_NOTICE, - LogLevel::WARNING => LOG_WARNING, - LogLevel::ERROR => LOG_ERR, - LogLevel::CRITICAL => LOG_CRIT, - LogLevel::ALERT => LOG_ALERT, - LogLevel::EMERGENCY => LOG_EMERG, - ]; - - /** - * Translates log priorities to string outputs - * @var array - */ - private $logToString = [ - LOG_DEBUG => 'DEBUG', - LOG_INFO => 'INFO', - LOG_NOTICE => 'NOTICE', - LOG_WARNING => 'WARNING', - LOG_ERR => 'ERROR', - LOG_CRIT => 'CRITICAL', - LOG_ALERT => 'ALERT', - LOG_EMERG => 'EMERGENCY' - ]; - - /** - * The channel of the current process (added to each message) - * @var string - */ - private $channel; - - /** - * Indicates what logging options will be used when generating a log message - * @see http://php.net/manual/en/function.openlog.php#refsect1-function.openlog-parameters - * - * @var int - */ - private $logOpts; - - /** - * Used to specify what type of program is logging the message - * @see http://php.net/manual/en/function.openlog.php#refsect1-function.openlog-parameters - * - * @var int - */ - private $logFacility; - - /** - * The minimum loglevel at which this logger will be triggered - * @var int - */ - private $logLevel; - - /** - * The Introspection for the current call - * @var Introspection - */ - private $introspection; - - /** - * The UID of the current call - * @var string - */ - private $logUid; - - /** - * @param string $channel The output channel - * @param Introspection $introspection The introspection of the current call - * @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, $level = LogLevel::NOTICE, $logOpts = LOG_PID, $logFacility = LOG_USER) + public function __construct($channel, Introspection $introspection, Profiler $profiler) { - $this->logUid = Strings::getRandomHex(6); - $this->channel = $channel; - $this->logOpts = $logOpts; - $this->logFacility = $logFacility; - $this->logLevel = $this->mapLevelToPriority($level); - $this->introspection = $introspection; + parent::__construct($channel, $introspection, $profiler); } /** - * Maps the LogLevel (@see LogLevel ) to a SysLog priority (@see http://php.net/manual/en/function.syslog.php#refsect1-function.syslog-parameters ) - * - * @param string $level A LogLevel - * - * @return int The SysLog priority - * - * @throws \Psr\Log\InvalidArgumentException If the loglevel isn't valid - */ - public function mapLevelToPriority($level) - { - if (!array_key_exists($level, $this->logLevels)) { - throw new InvalidArgumentException('LogLevel \'' . $level . '\' isn\'t valid.'); - } - - return $this->logLevels[$level]; - } - - /** - * Writes a message to the syslog - * @see http://php.net/manual/en/function.syslog.php#refsect1-function.syslog-parameters - * - * @param int $priority The Priority - * @param string $message The message of the log - * - * @throws InternalServerErrorException if syslog cannot be used - */ - private function write($priority, $message) - { - if (!openlog(self::IDENT, $this->logOpts, $this->logFacility)) { - throw new InternalServerErrorException('Can\'t open syslog for ident "' . $this->channel . '" and facility "' . $this->logFacility . '""'); - } - - syslog($priority, $message); - } - - /** - * Closes the Syslog - */ - public function close() - { - closelog(); - } - - /** - * 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]); - $logMessage = ''; - - $logMessage .= $this->channel . ' '; - $logMessage .= '[' . $this->logToString[$level] . ']: '; - $logMessage .= $this->psrInterpolate($message, $context) . ' '; - $logMessage .= @json_encode($context) . ' - '; - $logMessage .= @json_encode($record); - - return $logMessage; - } - - /** - * Simple interpolation of PSR-3 compliant replacements ( variables between '{' and '}' ) - * @see https://www.php-fig.org/psr/psr-3/#12-message + * Adds a new entry to the log * + * @param int $level * @param string $message - * @param array $context + * @param array $context * - * @return string the interpolated message + * @return void */ - private function psrInterpolate($message, array $context = array()) + protected function addEntry($level, $message, $context = []) { - $replace = []; - foreach ($context as $key => $value) { - // check that the value can be casted to string - if (!is_array($value) && (!is_object($value) || method_exists($value, '__toString'))) { - $replace['{' . $key . '}'] = $value; - } elseif (is_array($value)) { - $replace['{' . $key . '}'] = @json_encode($value); - } - } - - return strtr($message, $replace); - } - - /** - * Adds a new entry to the syslog - * - * @param int $level - * @param string $message - * @param array $context - * - * @throws InternalServerErrorException if the syslog isn't available - */ - private function addEntry($level, $message, $context = []) - { - if ($level >= $this->logLevel) { - return; - } - - $formattedLog = $this->formatLog($level, $message, $context); - $this->write($level, $formattedLog); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function emergency($message, array $context = array()) - { - $this->addEntry(LOG_EMERG, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function alert($message, array $context = array()) - { - $this->addEntry(LOG_ALERT, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function critical($message, array $context = array()) - { - $this->addEntry(LOG_CRIT, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function error($message, array $context = array()) - { - $this->addEntry(LOG_ERR, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function warning($message, array $context = array()) - { - $this->addEntry(LOG_WARNING, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function notice($message, array $context = array()) - { - $this->addEntry(LOG_NOTICE, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function info($message, array $context = array()) - { - $this->addEntry(LOG_INFO, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function debug($message, array $context = array()) - { - $this->addEntry(LOG_DEBUG, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function log($level, $message, array $context = array()) - { - $logLevel = $this->mapLevelToPriority($level); - $this->addEntry($logLevel, $message, $context); + // TODO: Implement addEntry() method. } } diff --git a/src/Util/Logger/SyslogLogger.php b/src/Util/Logger/SyslogLogger.php index 5cb1f8c9e6..25d8f2f5e2 100644 --- a/src/Util/Logger/SyslogLogger.php +++ b/src/Util/Logger/SyslogLogger.php @@ -4,16 +4,15 @@ namespace Friendica\Util\Logger; use Friendica\Network\HTTPException\InternalServerErrorException; use Friendica\Util\Introspection; -use Friendica\Util\Strings; +use Friendica\Util\Profiler; use Psr\Log\InvalidArgumentException; -use Psr\Log\LoggerInterface; use Psr\Log\LogLevel; /** * A Logger instance for syslogging (fast, but simple) * @see http://php.net/manual/en/function.syslog.php */ -class SyslogLogger implements LoggerInterface +class SyslogLogger extends AbstractFriendicaLogger { const IDENT = 'Friendica'; @@ -47,12 +46,6 @@ class SyslogLogger implements LoggerInterface LOG_EMERG => 'EMERGENCY' ]; - /** - * The channel of the current process (added to each message) - * @var string - */ - private $channel; - /** * Indicates what logging options will be used when generating a log message * @see http://php.net/manual/en/function.openlog.php#refsect1-function.openlog-parameters @@ -76,34 +69,20 @@ class SyslogLogger implements LoggerInterface private $logLevel; /** - * The Introspection for the current call - * @var Introspection - */ - private $introspection; - - /** - * The UID of the current call - * @var string - */ - private $logUid; - - /** - * @param string $channel The output channel - * @param Introspection $introspection The introspection of the current call + * {@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 * * @throws \Exception */ - public function __construct($channel, Introspection $introspection, $level = LogLevel::NOTICE, $logOpts = LOG_PID, $logFacility = LOG_USER) + public function __construct($channel, Introspection $introspection, Profiler $profiler, $level = LogLevel::NOTICE, $logOpts = LOG_PID, $logFacility = LOG_USER) { - $this->logUid = Strings::getRandomHex(6); - $this->channel = $channel; + parent::__construct($channel, $introspection, $profiler); $this->logOpts = $logOpts; $this->logFacility = $logFacility; $this->logLevel = $this->mapLevelToPriority($level); - $this->introspection = $introspection; + $this->introspection->addClasses(array(self::class)); } /** @@ -174,30 +153,6 @@ class SyslogLogger implements LoggerInterface return $logMessage; } - /** - * Simple interpolation of PSR-3 compliant replacements ( variables between '{' and '}' ) - * @see https://www.php-fig.org/psr/psr-3/#12-message - * - * @param string $message - * @param array $context - * - * @return string the interpolated message - */ - private function psrInterpolate($message, array $context = array()) - { - $replace = []; - foreach ($context as $key => $value) { - // check that the value can be casted to string - if (!is_array($value) && (!is_object($value) || method_exists($value, '__toString'))) { - $replace['{' . $key . '}'] = $value; - } elseif (is_array($value)) { - $replace['{' . $key . '}'] = @json_encode($value); - } - } - - return strtr($message, $replace); - } - /** * Adds a new entry to the syslog * @@ -207,95 +162,15 @@ class SyslogLogger implements LoggerInterface * * @throws InternalServerErrorException if the syslog isn't available */ - private function addEntry($level, $message, $context = []) + protected function addEntry($level, $message, $context = []) { - if ($level >= $this->logLevel) { + $logLevel = $this->mapLevelToPriority($level); + + if ($logLevel >= $this->logLevel) { return; } $formattedLog = $this->formatLog($level, $message, $context); $this->write($level, $formattedLog); } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function emergency($message, array $context = array()) - { - $this->addEntry(LOG_EMERG, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function alert($message, array $context = array()) - { - $this->addEntry(LOG_ALERT, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function critical($message, array $context = array()) - { - $this->addEntry(LOG_CRIT, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function error($message, array $context = array()) - { - $this->addEntry(LOG_ERR, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function warning($message, array $context = array()) - { - $this->addEntry(LOG_WARNING, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function notice($message, array $context = array()) - { - $this->addEntry(LOG_NOTICE, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function info($message, array $context = array()) - { - $this->addEntry(LOG_INFO, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function debug($message, array $context = array()) - { - $this->addEntry(LOG_DEBUG, $message, $context); - } - - /** - * {@inheritdoc} - * @throws InternalServerErrorException if the syslog isn't available - */ - public function log($level, $message, array $context = array()) - { - $logLevel = $this->mapLevelToPriority($level); - $this->addEntry($logLevel, $message, $context); - } } diff --git a/tests/include/ApiTest.php b/tests/include/ApiTest.php index 289b3fcea5..c43deea405 100644 --- a/tests/include/ApiTest.php +++ b/tests/include/ApiTest.php @@ -43,7 +43,7 @@ class ApiTest extends DatabaseTest Factory\DBFactory::init($configCache, $profiler, $_SERVER); $config = Factory\ConfigFactory::createConfig($configCache); Factory\ConfigFactory::createPConfig($configCache); - $logger = Factory\LoggerFactory::create('test', $config); + $logger = Factory\LoggerFactory::create('test', $config, $profiler); $this->app = new App($config, $logger, $profiler, false); parent::setUp(); diff --git a/tests/src/Database/DBATest.php b/tests/src/Database/DBATest.php index e8b9c68b19..c6f2fae6dd 100644 --- a/tests/src/Database/DBATest.php +++ b/tests/src/Database/DBATest.php @@ -20,7 +20,7 @@ class DBATest extends DatabaseTest Factory\DBFactory::init($configCache, $profiler, $_SERVER); $config = Factory\ConfigFactory::createConfig($configCache); Factory\ConfigFactory::createPConfig($configCache); - $logger = Factory\LoggerFactory::create('test', $config); + $logger = Factory\LoggerFactory::create('test', $config, $profiler); $this->app = new App($config, $logger, $profiler, false); parent::setUp(); diff --git a/tests/src/Database/DBStructureTest.php b/tests/src/Database/DBStructureTest.php index 325ad4e5e7..fde41dab01 100644 --- a/tests/src/Database/DBStructureTest.php +++ b/tests/src/Database/DBStructureTest.php @@ -20,7 +20,7 @@ class DBStructureTest extends DatabaseTest Factory\DBFactory::init($configCache, $profiler, $_SERVER); $config = Factory\ConfigFactory::createConfig($configCache); Factory\ConfigFactory::createPConfig($configCache); - $logger = Factory\LoggerFactory::create('test', $config); + $logger = Factory\LoggerFactory::create('test', $config, $profiler); $this->app = new App($config, $logger, $profiler, false); parent::setUp(); From 8f7fc9db60812d8133a85bf1021bcb95539c10b4 Mon Sep 17 00:00:00 2001 From: Philipp Holzer Date: Thu, 28 Feb 2019 09:48:55 +0100 Subject: [PATCH 3/9] cleanup sysloglogger --- config/defaults.config.php | 2 +- src/Factory/LoggerFactory.php | 26 +++++++-- src/Util/Logger/AbstractFriendicaLogger.php | 18 +++---- src/Util/Logger/StreamLogger.php | 11 +++- src/Util/Logger/SyslogLogger.php | 58 ++++++++++----------- 5 files changed, 69 insertions(+), 46 deletions(-) diff --git a/config/defaults.config.php b/config/defaults.config.php index d40d0c68d8..155388aab3 100644 --- a/config/defaults.config.php +++ b/config/defaults.config.php @@ -210,7 +210,7 @@ return [ 'local_tags' => false, // logger_adapter (String) - // Sets the logging adapter of Friendica globally (monolog, syslog) + // Sets the logging adapter of Friendica globally (monolog, syslog, stream) 'logger_adapter' => 'monolog', // max_batch_queue (Integer) diff --git a/src/Factory/LoggerFactory.php b/src/Factory/LoggerFactory.php index ce8d9f2c9c..087ce5d0b0 100644 --- a/src/Factory/LoggerFactory.php +++ b/src/Factory/LoggerFactory.php @@ -6,8 +6,10 @@ use Friendica\Core\Config\Configuration; use Friendica\Core\Logger; use Friendica\Network\HTTPException\InternalServerErrorException; use Friendica\Util\Introspection; +use Friendica\Util\Logger\AbstractFriendicaLogger; use Friendica\Util\Logger\Monolog\FriendicaDevelopHandler; use Friendica\Util\Logger\Monolog\FriendicaIntrospectionProcessor; +use Friendica\Util\Logger\StreamLogger; use Friendica\Util\Logger\SyslogLogger; use Friendica\Util\Logger\VoidLogger; use Friendica\Util\Profiler; @@ -22,6 +24,16 @@ use Psr\Log\LogLevel; */ class LoggerFactory { + /** + * A list of classes, which shouldn't get logged + * @var array + */ + private static $ignoreClassList = [ + Logger::class, + Profiler::class, + 'Friendica\\Util\\Logger', + ]; + /** * Creates a new PSR-3 compliant logger instances * @@ -41,14 +53,19 @@ class LoggerFactory return $logger; } - $introspection = new Introspection([Logger::class, Profiler::class]); + $introspection = new Introspection(self::$ignoreClassList); + $level = $config->get('system', 'loglevel'); switch ($config->get('system', 'logger_adapter', 'monolog')) { - case 'syslog': - $level = $config->get('system', 'loglevel'); + case 'syslog': $logger = new SyslogLogger($channel, $introspection, $profiler, $level); break; + + case 'stream': + $logger = new StreamLogger($channel, $introspection, $profiler, $level); + break; + case 'monolog': default: $logger = new Monolog\Logger($channel); @@ -58,7 +75,6 @@ class LoggerFactory $logger->pushProcessor(new FriendicaIntrospectionProcessor($introspection, LogLevel::DEBUG)); $stream = $config->get('system', 'logfile'); - $level = $config->get('system', 'loglevel'); $loglevel = self::mapLegacyConfigDebugLevel((string)$level); static::addStreamHandler($logger, $stream, $loglevel); @@ -93,7 +109,7 @@ class LoggerFactory return null; } - $introspection = new Introspection([Logger::class, SyslogLogger::class, Profiler::class]); + $introspection = new Introspection(self::$ignoreClassList); $logger = new Monolog\Logger($channel); $logger->pushProcessor(new Monolog\Processor\PsrLogMessageProcessor()); diff --git a/src/Util/Logger/AbstractFriendicaLogger.php b/src/Util/Logger/AbstractFriendicaLogger.php index 3f851f42de..326ee05004 100644 --- a/src/Util/Logger/AbstractFriendicaLogger.php +++ b/src/Util/Logger/AbstractFriendicaLogger.php @@ -99,7 +99,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface public function emergency($message, array $context = array()) { $stamp1 = microtime(true); - $this->addEntry(LogLevel::EMERGENCY, $message, $context); + $this->addEntry(LogLevel::EMERGENCY, (string) $message, $context); $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } @@ -109,7 +109,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface public function alert($message, array $context = array()) { $stamp1 = microtime(true); - $this->addEntry(LogLevel::ALERT, $message, $context); + $this->addEntry(LogLevel::ALERT, (string) $message, $context); $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } @@ -119,7 +119,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface public function critical($message, array $context = array()) { $stamp1 = microtime(true); - $this->addEntry(LogLevel::CRITICAL, $message, $context); + $this->addEntry(LogLevel::CRITICAL, (string) $message, $context); $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } @@ -129,7 +129,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface public function error($message, array $context = array()) { $stamp1 = microtime(true); - $this->addEntry(LogLevel::ERROR, $message, $context); + $this->addEntry(LogLevel::ERROR, (string) $message, $context); $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } @@ -139,7 +139,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface public function warning($message, array $context = array()) { $stamp1 = microtime(true); - $this->addEntry(LogLevel::WARNING, $message, $context); + $this->addEntry(LogLevel::WARNING, (string) $message, $context); $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } @@ -149,7 +149,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface public function notice($message, array $context = array()) { $stamp1 = microtime(true); - $this->addEntry(LogLevel::NOTICE, $message, $context); + $this->addEntry(LogLevel::NOTICE, (string) $message, $context); $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } @@ -159,7 +159,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface public function info($message, array $context = array()) { $stamp1 = microtime(true); - $this->addEntry(LogLevel::INFO, $message, $context); + $this->addEntry(LogLevel::INFO, (string) $message, $context); $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } @@ -169,7 +169,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface public function debug($message, array $context = array()) { $stamp1 = microtime(true); - $this->addEntry(LogLevel::DEBUG, $message, $context); + $this->addEntry(LogLevel::DEBUG, (string) $message, $context); $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } @@ -179,7 +179,7 @@ abstract class AbstractFriendicaLogger implements LoggerInterface public function log($level, $message, array $context = array()) { $stamp1 = microtime(true); - $this->addEntry($level, $message, $context); + $this->addEntry($level, (string) $message, $context); $this->profiler->saveTimestamp($stamp1, 'file', System::callstack()); } } diff --git a/src/Util/Logger/StreamLogger.php b/src/Util/Logger/StreamLogger.php index 4ccbc8283b..8d9ffec387 100644 --- a/src/Util/Logger/StreamLogger.php +++ b/src/Util/Logger/StreamLogger.php @@ -6,13 +6,20 @@ use Friendica\Util\Introspection; use Friendica\Util\Profiler; /** - * A Logger instance for logging into a stream + * A Logger instance for logging into a stream (file, stdout, stderr) */ class StreamLogger extends AbstractFriendicaLogger { - public function __construct($channel, Introspection $introspection, Profiler $profiler) + /** + * The minimum loglevel at which this logger will be triggered + * @var string + */ + private $logLevel; + + public function __construct($channel, Introspection $introspection, Profiler $profiler, $level) { parent::__construct($channel, $introspection, $profiler); + $this->logLevel = $level; } /** diff --git a/src/Util/Logger/SyslogLogger.php b/src/Util/Logger/SyslogLogger.php index 25d8f2f5e2..cff7125e5b 100644 --- a/src/Util/Logger/SyslogLogger.php +++ b/src/Util/Logger/SyslogLogger.php @@ -85,6 +85,27 @@ class SyslogLogger extends AbstractFriendicaLogger $this->introspection->addClasses(array(self::class)); } + /** + * Adds a new entry to the syslog + * + * @param int $level + * @param string $message + * @param array $context + * + * @throws InternalServerErrorException if the syslog isn't available + */ + protected function addEntry($level, $message, $context = []) + { + $logLevel = $this->mapLevelToPriority($level); + + if ($logLevel >= $this->logLevel) { + return; + } + + $formattedLog = $this->formatLog($logLevel, $message, $context); + $this->write($logLevel, $formattedLog); + } + /** * Maps the LogLevel (@see LogLevel ) to a SysLog priority (@see http://php.net/manual/en/function.syslog.php#refsect1-function.syslog-parameters ) * @@ -103,6 +124,14 @@ class SyslogLogger extends AbstractFriendicaLogger return $this->logLevels[$level]; } + /** + * Closes the Syslog + */ + public function close() + { + closelog(); + } + /** * Writes a message to the syslog * @see http://php.net/manual/en/function.syslog.php#refsect1-function.syslog-parameters @@ -121,14 +150,6 @@ class SyslogLogger extends AbstractFriendicaLogger syslog($priority, $message); } - /** - * Closes the Syslog - */ - public function close() - { - closelog(); - } - /** * Formats a log record for the syslog output * @@ -152,25 +173,4 @@ class SyslogLogger extends AbstractFriendicaLogger return $logMessage; } - - /** - * Adds a new entry to the syslog - * - * @param int $level - * @param string $message - * @param array $context - * - * @throws InternalServerErrorException if the syslog isn't available - */ - protected function addEntry($level, $message, $context = []) - { - $logLevel = $this->mapLevelToPriority($level); - - if ($logLevel >= $this->logLevel) { - return; - } - - $formattedLog = $this->formatLog($level, $message, $context); - $this->write($level, $formattedLog); - } } From 676ea1f6f6e311e4e375f3aa53411b1f2920d847 Mon Sep 17 00:00:00 2001 From: Philipp Holzer Date: Sun, 3 Mar 2019 15:20:26 +0100 Subject: [PATCH 4/9] Added VoidLogger for CurResultTest --- tests/src/Network/CurlResultTest.php | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/tests/src/Network/CurlResultTest.php b/tests/src/Network/CurlResultTest.php index bb0bcf2471..b542371b39 100644 --- a/tests/src/Network/CurlResultTest.php +++ b/tests/src/Network/CurlResultTest.php @@ -2,11 +2,20 @@ namespace Friendica\Test\src\Network; +use Friendica\Core\Logger; use Friendica\Network\CurlResult; +use Friendica\Util\Logger\VoidLogger; use PHPUnit\Framework\TestCase; class CurlResultTest extends TestCase { + protected function setUp() + { + parent::setUp(); + + Logger::init(new VoidLogger()); + } + /** * @small */ From 917e3ae316ce1f0f2833db4757f1b39edd0fe591 Mon Sep 17 00:00:00 2001 From: Philipp Holzer Date: Sun, 3 Mar 2019 20:32:27 +0100 Subject: [PATCH 5/9] 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 155388aab3..b3f195e692 100644 --- a/config/defaults.config.php +++ b/config/defaults.config.php @@ -209,9 +209,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 087ce5d0b0..4a17cb3073 100644 --- a/src/Factory/LoggerFactory.php +++ b/src/Factory/LoggerFactory.php @@ -6,9 +6,9 @@ use Friendica\Core\Config\Configuration; use Friendica\Core\Logger; use Friendica\Network\HTTPException\InternalServerErrorException; use Friendica\Util\Introspection; -use Friendica\Util\Logger\AbstractFriendicaLogger; 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; @@ -56,18 +56,9 @@ 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: $logger = new Monolog\Logger($channel); $logger->pushProcessor(new Monolog\Processor\PsrLogMessageProcessor()); $logger->pushProcessor(new Monolog\Processor\ProcessIdProcessor()); @@ -79,6 +70,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); @@ -96,30 +104,56 @@ 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 \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; } $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; } From 95725604d80a9dd1ec664246fff355437074b19e Mon Sep 17 00:00:00 2001 From: Philipp Holzer Date: Sun, 3 Mar 2019 21:25:18 +0100 Subject: [PATCH 6/9] Added StreamLoggerTest --- src/Util/Logger/StreamLogger.php | 24 ++- tests/src/Util/Logger/StreamLoggerTest.php | 203 +++++++++++++++++++++ 2 files changed, 223 insertions(+), 4 deletions(-) create mode 100644 tests/src/Util/Logger/StreamLoggerTest.php diff --git a/src/Util/Logger/StreamLogger.php b/src/Util/Logger/StreamLogger.php index ad1b152d9e..10ad0a0976 100644 --- a/src/Util/Logger/StreamLogger.php +++ b/src/Util/Logger/StreamLogger.php @@ -35,6 +35,12 @@ class StreamLogger extends AbstractFriendicaLogger */ private $pid; + /** + * An error message + * @var string + */ + private $errorMessage; + /** * Translates LogLevel log levels to integer values * @var array @@ -98,7 +104,7 @@ class StreamLogger extends AbstractFriendicaLogger protected function addEntry($level, $message, $context = []) { if (!array_key_exists($level, $this->levelToInt)) { - throw new \InvalidArgumentException('The level "%s" is not valid', $level); + throw new \InvalidArgumentException(sprintf('The level "%s" is not valid.', $level)); } $logLevel = $this->levelToInt[$level]; @@ -151,12 +157,14 @@ class StreamLogger extends AbstractFriendicaLogger } $this->createDir(); - $this->stream = fopen($this->url, 'a'); + set_error_handler([$this, 'customErrorHandler']); + $this->stream = fopen($this->url, 'ab'); + restore_error_handler(); if (!is_resource($this->stream)) { $this->stream = null; - throw new \UnexpectedValueException(sprintf('The stream or file "%s" could not be opened.', $this->url)); + throw new \UnexpectedValueException(sprintf('The stream or file "%s" could not be opened: ' . $this->errorMessage, $this->url)); } } @@ -173,10 +181,18 @@ class StreamLogger extends AbstractFriendicaLogger } if (isset($dirname) && !is_dir($dirname)) { + set_error_handler([$this, 'customErrorHandler']); $status = mkdir($dirname, 0777, true); + restore_error_handler(); + if (!$status && !is_dir($dirname)) { - throw new \UnexpectedValueException(sprintf('Directory "%s" cannot get created.', $dirname)); + throw new \UnexpectedValueException(sprintf('Directory "%s" cannot get created: ' . $this->errorMessage, $dirname)); } } } + + private function customErrorHandler($code, $msg) + { + $this->errorMessage = preg_replace('{^(fopen|mkdir)\(.*?\): }', '', $msg); + } } diff --git a/tests/src/Util/Logger/StreamLoggerTest.php b/tests/src/Util/Logger/StreamLoggerTest.php new file mode 100644 index 0000000000..a2e81441b2 --- /dev/null +++ b/tests/src/Util/Logger/StreamLoggerTest.php @@ -0,0 +1,203 @@ +setUpVfsDir(); + + $this->introspection = \Mockery::mock(Introspection::class); + $this->introspection->shouldReceive('getRecord')->andReturn([ + 'file' => self::FILE, + 'line' => self::LINE, + 'function' => self::FUNC + ]); + } + + public function assertLogline($string) + { + $this->assertRegExp(self::LOGLINE, $string); + } + + public function assertLoglineNums($assertNum, $string) + { + $this->assertEquals($assertNum, preg_match_all(self::LOGLINE, $string)); + } + + public function testNormal() + { + $logfile = vfsStream::newFile('friendica.log') + ->at($this->root); + + $logger = new StreamLogger('test', $logfile->url(), $this->introspection); + $logger->emergency('working!'); + $logger->alert('working too!'); + $logger->debug('and now?'); + $logger->notice('message', ['an' => 'context']); + + $text = $logfile->getContent(); + $this->assertLogline($text); + $this->assertLoglineNums(4, $text); + } + + /** + * Test if a log entry is correctly interpolated + */ + public function testPsrInterpolate() + { + $logfile = vfsStream::newFile('friendica.log') + ->at($this->root); + + $logger = new StreamLogger('test', $logfile->url(), $this->introspection); + + $logger->emergency('A {psr} test', ['psr' => 'working']); + $logger->alert('An {array} test', ['array' => ['it', 'is', 'working']]); + $text = $logfile->getContent(); + $this->assertContains('A working test', $text); + $this->assertContains('An ["it","is","working"] test', $text); + } + + /** + * Test if a log entry contains all necessary information + */ + public function testContainsInformation() + { + $logfile = vfsStream::newFile('friendica.log') + ->at($this->root); + + $logger = new StreamLogger('test', $logfile->url(), $this->introspection); + + $logger->emergency('A test'); + + $text = $logfile->getContent(); + $this->assertContains('"process_id":' . getmypid(), $text); + $this->assertContains('"file":"' . self::FILE . '"', $text); + $this->assertContains('"line":' . self::LINE, $text); + $this->assertContains('"function":"' . self::FUNC . '"', $text); + } + + /** + * Test if the minimum level is working + */ + public function testMinimumLevel() + { + $logfile = vfsStream::newFile('friendica.log') + ->at($this->root); + + $logger = new StreamLogger('test', $logfile->url(), $this->introspection, LogLevel::NOTICE); + + $logger->emergency('working'); + $logger->alert('working'); + $logger->error('working'); + $logger->warning('working'); + $logger->notice('working'); + $logger->info('not working'); + $logger->debug('not working'); + + $text = $logfile->getContent(); + + $this->assertLoglineNums(5, $text); + } + + + /** + * Test if a file cannot get opened + * @expectedException \UnexpectedValueException + */ + public function testNoFile() + { + $logfile = vfsStream::newFile('friendica.log') + ->at($this->root) + ->chmod(0); + + $logger = new StreamLogger('test', $logfile->url(), $this->introspection); + + $logger->emergency('not working'); + } + + /** + * Test when a file isn't set + * @expectedException \LogicException + * @expectedExceptionMessage Missing stream URL. + */ + public function testNoUrl() + { + $logger = new StreamLogger('test', '', $this->introspection); + + $logger->emergency('not working'); + } + + /** + * Test when a file doesn't exist + * @expectedException \UnexpectedValueException + * @expectedExceptionMessageRegExp /The stream or file .* could not be opened: .* / + */ + public function testWrongUrl() + { + $logger = new StreamLogger('test', 'wrongfile', $this->introspection); + + $logger->emergency('not working'); + } + + /** + * Test when the directory cannot get created + * @expectedException \UnexpectedValueException + * @expectedExceptionMessageRegExp /Directory .* cannot get created: .* / + */ + public function testWrongDir() + { + $logger = new StreamLogger('test', 'a/wrong/directory/file.txt', $this->introspection); + + $logger->emergency('not working'); + } + + /** + * Test when the minimum level is not valid + * @expectedException \InvalidArgumentException + * @expectedExceptionMessageRegExp /The level ".*" is not valid./ + */ + public function testWrongMinimumLevel() + { + $logger = new StreamLogger('test', 'file.text', $this->introspection, 'NOPE'); + } + + /** + * Test when the minimum level is not valid + * @expectedException \InvalidArgumentException + * @expectedExceptionMessageRegExp /The level ".*" is not valid./ + */ + public function testWrongLogLevel() + { + $logfile = vfsStream::newFile('friendica.log') + ->at($this->root); + + $logger = new StreamLogger('test', $logfile->url(), $this->introspection); + + $logger->log('NOPE', 'a test'); + } +} From 2238d516504b2bf28811065961ebf0ed68d7e7e2 Mon Sep 17 00:00:00 2001 From: Philipp Holzer Date: Sun, 3 Mar 2019 21:38:33 +0100 Subject: [PATCH 7/9] typo --- src/Util/Logger/{REAMDE.md => README.md} | 0 1 file changed, 0 insertions(+), 0 deletions(-) rename src/Util/Logger/{REAMDE.md => README.md} (100%) diff --git a/src/Util/Logger/REAMDE.md b/src/Util/Logger/README.md similarity index 100% rename from src/Util/Logger/REAMDE.md rename to src/Util/Logger/README.md From e0017e50f94b9e5aaaad89d99308f28b44352c95 Mon Sep 17 00:00:00 2001 From: Philipp Holzer Date: Mon, 4 Mar 2019 08:42:08 +0100 Subject: [PATCH 8/9] Rename & Testfix --- src/Factory/LoggerFactory.php | 10 ++++---- ...FriendicaLogger.php => AbstractLogger.php} | 2 +- ...aDevelopHandler.php => DevelopHandler.php} | 2 +- ...ocessor.php => IntrospectionProcessor.php} | 2 +- src/Util/Logger/README.md | 4 +-- src/Util/Logger/StreamLogger.php | 2 +- src/Util/Logger/SyslogLogger.php | 2 +- tests/src/Util/Logger/StreamLoggerTest.php | 25 +++++-------------- 8 files changed, 17 insertions(+), 32 deletions(-) rename src/Util/Logger/{AbstractFriendicaLogger.php => AbstractLogger.php} (98%) rename src/Util/Logger/Monolog/{FriendicaDevelopHandler.php => DevelopHandler.php} (95%) rename src/Util/Logger/Monolog/{FriendicaIntrospectionProcessor.php => IntrospectionProcessor.php} (93%) diff --git a/src/Factory/LoggerFactory.php b/src/Factory/LoggerFactory.php index 4a17cb3073..274044eb29 100644 --- a/src/Factory/LoggerFactory.php +++ b/src/Factory/LoggerFactory.php @@ -6,8 +6,8 @@ use Friendica\Core\Config\Configuration; use Friendica\Core\Logger; 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\Monolog\DevelopHandler; +use Friendica\Util\Logger\Monolog\IntrospectionProcessor; use Friendica\Util\Logger\ProfilerLogger; use Friendica\Util\Logger\StreamLogger; use Friendica\Util\Logger\SyslogLogger; @@ -63,7 +63,7 @@ class LoggerFactory $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)); + $logger->pushProcessor(new IntrospectionProcessor($introspection, LogLevel::DEBUG)); $stream = $config->get('system', 'logfile'); @@ -131,9 +131,9 @@ class LoggerFactory $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)); + $logger->pushProcessor(new IntrospectionProcessor($introspection, LogLevel::DEBUG)); - $logger->pushHandler(new FriendicaDevelopHandler($developerIp)); + $logger->pushHandler(new DevelopHandler($developerIp)); static::addStreamHandler($logger, $stream, LogLevel::DEBUG); break; diff --git a/src/Util/Logger/AbstractFriendicaLogger.php b/src/Util/Logger/AbstractLogger.php similarity index 98% rename from src/Util/Logger/AbstractFriendicaLogger.php rename to src/Util/Logger/AbstractLogger.php index 82f2f56c53..576f4bfb43 100644 --- a/src/Util/Logger/AbstractFriendicaLogger.php +++ b/src/Util/Logger/AbstractLogger.php @@ -16,7 +16,7 @@ use Psr\Log\LogLevel; * - UID for each call * - Channel of the current call (i.e. index, worker, daemon, ...) */ -abstract class AbstractFriendicaLogger implements LoggerInterface +abstract class AbstractLogger implements LoggerInterface { /** * The output channel of this logger diff --git a/src/Util/Logger/Monolog/FriendicaDevelopHandler.php b/src/Util/Logger/Monolog/DevelopHandler.php similarity index 95% rename from src/Util/Logger/Monolog/FriendicaDevelopHandler.php rename to src/Util/Logger/Monolog/DevelopHandler.php index 13a4645357..07a839345a 100644 --- a/src/Util/Logger/Monolog/FriendicaDevelopHandler.php +++ b/src/Util/Logger/Monolog/DevelopHandler.php @@ -11,7 +11,7 @@ use Monolog\Logger; * If you want to debug only interactions from your IP or the IP of a remote server for federation debug, * you'll use Logger::develop() for the duration of your work, and you clean it up when you're done before submitting your PR. */ -class FriendicaDevelopHandler extends Handler\AbstractHandler +class DevelopHandler extends Handler\AbstractHandler { /** * @var string The IP of the developer who wants to debug diff --git a/src/Util/Logger/Monolog/FriendicaIntrospectionProcessor.php b/src/Util/Logger/Monolog/IntrospectionProcessor.php similarity index 93% rename from src/Util/Logger/Monolog/FriendicaIntrospectionProcessor.php rename to src/Util/Logger/Monolog/IntrospectionProcessor.php index b8e7f5e107..18ea84680b 100644 --- a/src/Util/Logger/Monolog/FriendicaIntrospectionProcessor.php +++ b/src/Util/Logger/Monolog/IntrospectionProcessor.php @@ -9,7 +9,7 @@ use Monolog\Processor\ProcessorInterface; /** * Injects line/file//function where the log message came from */ -class FriendicaIntrospectionProcessor implements ProcessorInterface +class IntrospectionProcessor implements ProcessorInterface { private $level; diff --git a/src/Util/Logger/README.md b/src/Util/Logger/README.md index 381bd94ba7..449403194d 100644 --- a/src/Util/Logger/README.md +++ b/src/Util/Logger/README.md @@ -24,6 +24,4 @@ Each logging implementation should pe capable of printing at least the following - 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. +If possible, a Logger should extend [`AbstractLogger`](AbstractLogger.php), because it contains additional, Friendica specific business logic for each logging call. diff --git a/src/Util/Logger/StreamLogger.php b/src/Util/Logger/StreamLogger.php index 10ad0a0976..7e52df80f1 100644 --- a/src/Util/Logger/StreamLogger.php +++ b/src/Util/Logger/StreamLogger.php @@ -9,7 +9,7 @@ use Psr\Log\LogLevel; /** * A Logger instance for logging into a stream (file, stdout, stderr) */ -class StreamLogger extends AbstractFriendicaLogger +class StreamLogger extends AbstractLogger { /** * The minimum loglevel at which this logger will be triggered diff --git a/src/Util/Logger/SyslogLogger.php b/src/Util/Logger/SyslogLogger.php index 2d4a5fe311..e21e953ac9 100644 --- a/src/Util/Logger/SyslogLogger.php +++ b/src/Util/Logger/SyslogLogger.php @@ -11,7 +11,7 @@ use Psr\Log\LogLevel; * A Logger instance for syslogging (fast, but simple) * @see http://php.net/manual/en/function.syslog.php */ -class SyslogLogger extends AbstractFriendicaLogger +class SyslogLogger extends AbstractLogger { const IDENT = 'Friendica'; diff --git a/tests/src/Util/Logger/StreamLoggerTest.php b/tests/src/Util/Logger/StreamLoggerTest.php index a2e81441b2..38706231ce 100644 --- a/tests/src/Util/Logger/StreamLoggerTest.php +++ b/tests/src/Util/Logger/StreamLoggerTest.php @@ -124,22 +124,6 @@ class StreamLoggerTest extends MockedTest $this->assertLoglineNums(5, $text); } - - /** - * Test if a file cannot get opened - * @expectedException \UnexpectedValueException - */ - public function testNoFile() - { - $logfile = vfsStream::newFile('friendica.log') - ->at($this->root) - ->chmod(0); - - $logger = new StreamLogger('test', $logfile->url(), $this->introspection); - - $logger->emergency('not working'); - } - /** * Test when a file isn't set * @expectedException \LogicException @@ -153,13 +137,16 @@ class StreamLoggerTest extends MockedTest } /** - * Test when a file doesn't exist + * Test when a file cannot be opened * @expectedException \UnexpectedValueException * @expectedExceptionMessageRegExp /The stream or file .* could not be opened: .* / */ public function testWrongUrl() { - $logger = new StreamLogger('test', 'wrongfile', $this->introspection); + $logfile = vfsStream::newFile('friendica.log') + ->at($this->root)->chmod(0); + + $logger = new StreamLogger('test', $logfile->url(), $this->introspection); $logger->emergency('not working'); } @@ -171,7 +158,7 @@ class StreamLoggerTest extends MockedTest */ public function testWrongDir() { - $logger = new StreamLogger('test', 'a/wrong/directory/file.txt', $this->introspection); + $logger = new StreamLogger('test', '/a/wrong/directory/file.txt', $this->introspection); $logger->emergency('not working'); } From a5854db0e558007160af11a1de1c794ce77d64fc Mon Sep 17 00:00:00 2001 From: Philipp Holzer Date: Mon, 4 Mar 2019 08:57:30 +0100 Subject: [PATCH 9/9] Fix php doc --- src/Util/Introspection.php | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/src/Util/Introspection.php b/src/Util/Introspection.php index aa8dce446c..6eec70954d 100644 --- a/src/Util/Introspection.php +++ b/src/Util/Introspection.php @@ -63,7 +63,8 @@ class Introspection * Checks if the current trace class or function has to be skipped * * @param array $trace The current trace array - * @param int $index The index of the current hierarchy level + * @param int $index The index of the current hierarchy level + * * @return bool True if the class or function should get skipped, otherwise false */ private function isTraceClassOrSkippedFunction(array $trace, $index)