Added StreamLogger and ProfilerLogger

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.

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')) {
+		switch ($config->get('system', 'logger_config', 'stream')) {
-
-			case 'syslog':
-				$logger = new SyslogLogger($channel, $introspection, $profiler, $level);
-				break;
-
-			case 'stream':
-				$logger = new StreamLogger($channel, $introspection, $profiler, $level);
-				break;
-
 			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,6 +132,9 @@ class LoggerFactory
 
 		$introspection = new Introspection(self::$ignoreClassList);
 
+		switch ($config->get('system', 'logger_config', 'stream')) {
+
+			case 'monolog':
 				$logger = new Monolog\Logger($channel);
 				$logger->pushProcessor(new Monolog\Processor\PsrLogMessageProcessor());
 				$logger->pushProcessor(new Monolog\Processor\ProcessIdProcessor());
@@ -128,6 +144,24 @@ class LoggerFactory
 				$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);
 

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());
 	}
 }

src/Util/Logger/ProfilerLogger.php

@@ -0,0 +1,127 @@
+<?php
+
+namespace Friendica\Util\Logger;
+
+use Friendica\Core\System;
+use Friendica\Util\Profiler;
+use Psr\Log\LoggerInterface;
+
+/**
+ * This Logger adds additional profiling data in case profiling is enabled.
+ * It uses a predefined logger.
+ */
+class ProfilerLogger implements LoggerInterface
+{
+	/**
+	 * The Logger of the current call
+	 * @var LoggerInterface
+	 */
+	private $logger;
+
+	/**
+	 * The Profiler for the current call
+	 * @var Profiler
+	 */
+	protected $profiler;
+
+	/**
+	 * ProfilerLogger constructor.
+	 * @param LoggerInterface $logger   The Logger of the current call
+	 * @param Profiler        $profiler The profiler of the current call
+	 */
+	public function __construct(LoggerInterface $logger, Profiler $profiler)
+	{
+		$this->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());
+	}
+}

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.

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);
+		parent::__construct($channel, $introspection);
-		$this->logLevel = $level;
+
+		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));
+			}
+		}
 	}
 }

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;
 
@@ -76,9 +75,9 @@ class SyslogLogger extends AbstractFriendicaLogger
 	 *
 	 * @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;
 		}