From 510f4e02c8994cea9ba89f33ca38c99dce26b548 Mon Sep 17 00:00:00 2001 From: Art4 Date: Sun, 12 Jan 2025 08:21:30 +0000 Subject: [PATCH] Add support for WorkerLogger decorator in LoggerManager, deprecate core Logger class, deprecate DI::workerLogger() --- src/Core/Logger.php | 6 ++++ src/Core/Logger/LoggerManager.php | 28 ++++++++++++------ src/Core/Worker.php | 30 +++++++++++++------- src/DI.php | 8 ++++++ tests/Unit/Core/Logger/LoggerManagerTest.php | 25 +++++++++++++++- 5 files changed, 76 insertions(+), 21 deletions(-) diff --git a/src/Core/Logger.php b/src/Core/Logger.php index c15271e841..83f26322e4 100644 --- a/src/Core/Logger.php +++ b/src/Core/Logger.php @@ -13,6 +13,8 @@ use Psr\Log\LoggerInterface; /** * Logger functions + * + * @deprecated 2025.02 Use constructor injection or `DI::logger()` instead */ class Logger { @@ -48,6 +50,8 @@ class Logger /** * Enable additional logging for worker usage * + * @deprecated + * * @param string $functionName The worker function, which got called * * @throws \Friendica\Network\HTTPException\InternalServerErrorException @@ -60,6 +64,8 @@ class Logger /** * Disable additional logging for worker usage + * + * @deprecated */ public static function disableWorker() { diff --git a/src/Core/Logger/LoggerManager.php b/src/Core/Logger/LoggerManager.php index 05234dea23..b3f23dae01 100644 --- a/src/Core/Logger/LoggerManager.php +++ b/src/Core/Logger/LoggerManager.php @@ -13,6 +13,7 @@ use Friendica\Core\Config\Capability\IManageConfigValues; use Friendica\Core\Logger\Capability\LogChannel; use Friendica\Core\Logger\Factory\LoggerFactory; use Friendica\Core\Logger\Type\ProfilerLogger; +use Friendica\Core\Logger\Type\WorkerLogger; use Friendica\Util\Profiler; use Psr\Log\LoggerInterface; use Psr\Log\LogLevel; @@ -31,6 +32,14 @@ final class LoggerManager */ private static $logger = null; + /** + * Workaround: $logChannel must be static + * because Dice always creates a new LoggerManager object + * + * @var LoggerInterface|null + */ + private static string $logChannel = LogChannel::DEFAULT; + private IManageConfigValues $config; private LoggerFactory $factory; @@ -41,8 +50,6 @@ final class LoggerManager private bool $profiling; - private string $logChannel; - public function __construct(IManageConfigValues $config, LoggerFactory $factory) { $this->config = $config; @@ -51,14 +58,12 @@ final class LoggerManager $this->debug = (bool) $config->get('system', 'debugging') ?? false; $this->logLevel = (string) $config->get('system', 'loglevel') ?? LogLevel::NOTICE; $this->profiling = (bool) $config->get('system', 'profiling') ?? false; - $this->logChannel = LogChannel::DEFAULT; } public function changeLogChannel(string $logChannel): void { - $this->logChannel = $logChannel; - - self::$logger = null; + self::$logChannel = $logChannel; + self::$logger = null; } /** @@ -67,19 +72,19 @@ final class LoggerManager public function getLogger(): LoggerInterface { if (self::$logger === null) { - self::$logger = $this->createProfiledLogger(); + self::$logger = $this->createLogger(); } return self::$logger; } - private function createProfiledLogger(): LoggerInterface + private function createLogger(): LoggerInterface { // Always create NullLogger if debug is disabled if ($this->debug === false) { $logger = new NullLogger(); } else { - $logger = $this->factory->createLogger($this->logLevel, $this->logChannel); + $logger = $this->factory->createLogger($this->logLevel, self::$logChannel); } if ($this->profiling === true) { @@ -88,6 +93,11 @@ final class LoggerManager $logger = new ProfilerLogger($logger, $profiler); } + // Decorate Logger as WorkerLogger for BC + if (self::$logChannel === LogChannel::WORKER) { + $logger = new WorkerLogger($logger); + } + return $logger; } } diff --git a/src/Core/Worker.php b/src/Core/Worker.php index 568fa2873f..a3252112c3 100644 --- a/src/Core/Worker.php +++ b/src/Core/Worker.php @@ -8,6 +8,8 @@ namespace Friendica\Core; use Friendica\Core\Cache\Enum\Duration; +use Friendica\Core\Logger\Capability\LogChannel; +use Friendica\Core\Logger\Type\WorkerLogger; use Friendica\Core\Worker\Entity\Process; use Friendica\Database\DBA; use Friendica\DI; @@ -537,9 +539,15 @@ class Worker self::coolDown(); - Logger::enableWorker($funcname); + DI::loggerManager()->changeLogChannel(LogChannel::WORKER); - Logger::info('Process start.', ['priority' => $queue['priority'], 'id' => $queue['id']]); + $logger = DI::logger(); + + if ($logger instanceOf WorkerLogger) { + $logger->setFunctionName($funcname); + } + + DI::logger()->info('Process start.', ['priority' => $queue['priority'], 'id' => $queue['id']]); $stamp = (float)microtime(true); @@ -559,19 +567,19 @@ class Worker try { call_user_func_array(sprintf('Friendica\Worker\%s::execute', $funcname), $argv); } catch (\Throwable $e) { - Logger::error('Uncaught exception in worker method execution', ['class' => get_class($e), 'message' => $e->getMessage(), 'code' => $e->getCode(), 'file' => $e->getFile() . ':' . $e->getLine(), 'trace' => $e->getTraceAsString(), 'previous' => $e->getPrevious()]); + DI::logger()->error('Uncaught exception in worker method execution', ['class' => get_class($e), 'message' => $e->getMessage(), 'code' => $e->getCode(), 'file' => $e->getFile() . ':' . $e->getLine(), 'trace' => $e->getTraceAsString(), 'previous' => $e->getPrevious()]); Worker::defer(); } } else { try { $funcname($argv, count($argv)); } catch (\Throwable $e) { - Logger::error('Uncaught exception in worker execution', ['message' => $e->getMessage(), 'code' => $e->getCode(), 'file' => $e->getFile() . ':' . $e->getLine(), 'trace' => $e->getTraceAsString(), 'previous' => $e->getPrevious()]); + DI::logger()->error('Uncaught exception in worker execution', ['message' => $e->getMessage(), 'code' => $e->getCode(), 'file' => $e->getFile() . ':' . $e->getLine(), 'trace' => $e->getTraceAsString(), 'previous' => $e->getPrevious()]); Worker::defer(); } } - Logger::disableWorker(); + DI::loggerManager()->changeLogChannel(LogChannel::DEFAULT); $appHelper->setQueue([]); @@ -591,7 +599,7 @@ class Worker $rest = round(max(0, $up_duration - (self::$db_duration + self::$lock_duration)), 2); $exec = round($duration, 2); - Logger::info('Performance:', ['function' => $funcname, 'state' => self::$state, 'count' => $dbcount, 'stat' => $dbstat, 'write' => $dbwrite, 'lock' => $dblock, 'total' => $dbtotal, 'rest' => $rest, 'exec' => $exec]); + DI::logger()->info('Performance:', ['function' => $funcname, 'state' => self::$state, 'count' => $dbcount, 'stat' => $dbstat, 'write' => $dbwrite, 'lock' => $dblock, 'total' => $dbtotal, 'rest' => $rest, 'exec' => $exec]); self::coolDown(); @@ -603,16 +611,16 @@ class Worker self::$lock_duration = 0; if ($duration > 3600) { - Logger::info('Longer than 1 hour.', ['priority' => $queue['priority'], 'id' => $queue['id'], 'duration' => round($duration / 60, 3)]); + DI::logger()->info('Longer than 1 hour.', ['priority' => $queue['priority'], 'id' => $queue['id'], 'duration' => round($duration / 60, 3)]); } elseif ($duration > 600) { - Logger::info('Longer than 10 minutes.', ['priority' => $queue['priority'], 'id' => $queue['id'], 'duration' => round($duration / 60, 3)]); + DI::logger()->info('Longer than 10 minutes.', ['priority' => $queue['priority'], 'id' => $queue['id'], 'duration' => round($duration / 60, 3)]); } elseif ($duration > 300) { - Logger::info('Longer than 5 minutes.', ['priority' => $queue['priority'], 'id' => $queue['id'], 'duration' => round($duration / 60, 3)]); + DI::logger()->info('Longer than 5 minutes.', ['priority' => $queue['priority'], 'id' => $queue['id'], 'duration' => round($duration / 60, 3)]); } elseif ($duration > 120) { - Logger::info('Longer than 2 minutes.', ['priority' => $queue['priority'], 'id' => $queue['id'], 'duration' => round($duration / 60, 3)]); + DI::logger()->info('Longer than 2 minutes.', ['priority' => $queue['priority'], 'id' => $queue['id'], 'duration' => round($duration / 60, 3)]); } - Logger::info('Process done.', ['function' => $funcname, 'priority' => $queue['priority'], 'retrial' => $queue['retrial'], 'id' => $queue['id'], 'duration' => round($duration, 3)]); + DI::logger()->info('Process done.', ['function' => $funcname, 'priority' => $queue['priority'], 'retrial' => $queue['retrial'], 'id' => $queue['id'], 'duration' => round($duration, 3)]); DI::profiler()->saveLog(DI::logger(), 'ID ' . $queue['id'] . ': ' . $funcname); } diff --git a/src/DI.php b/src/DI.php index 72be1f3aaa..7d1114ac5c 100644 --- a/src/DI.php +++ b/src/DI.php @@ -9,6 +9,7 @@ namespace Friendica; use Dice\Dice; use Friendica\Core\Logger\Capability\ICheckLoggerSettings; +use Friendica\Core\Logger\LoggerManager; use Friendica\Core\Logger\Util\LoggerSettingsCheck; use Friendica\Core\Session\Capability\IHandleSessions; use Friendica\Core\Session\Capability\IHandleUserSessions; @@ -324,6 +325,8 @@ abstract class DI } /** + * @deprecated 2025.02 Use `DI::loggerManager()` and `DI::logger()` instead + * * @return \Friendica\Core\Logger\Type\WorkerLogger */ public static function workerLogger() @@ -331,6 +334,11 @@ abstract class DI return self::$dice->create(Core\Logger\Type\WorkerLogger::class); } + public static function loggerManager(): LoggerManager + { + return self::$dice->create(LoggerManager::class); + } + // // "Factory" namespace instances // diff --git a/tests/Unit/Core/Logger/LoggerManagerTest.php b/tests/Unit/Core/Logger/LoggerManagerTest.php index 81096eee96..14db1c2676 100644 --- a/tests/Unit/Core/Logger/LoggerManagerTest.php +++ b/tests/Unit/Core/Logger/LoggerManagerTest.php @@ -14,6 +14,7 @@ use Friendica\Core\Logger\Capability\LogChannel; use Friendica\Core\Logger\Factory\LoggerFactory; use Friendica\Core\Logger\LoggerManager; use Friendica\Core\Logger\Type\ProfilerLogger; +use Friendica\Core\Logger\Type\WorkerLogger; use PHPUnit\Framework\TestCase; use Psr\Log\LoggerInterface; use Psr\Log\NullLogger; @@ -87,7 +88,7 @@ class LoggerManagerTest extends TestCase $this->assertInstanceOf(ProfilerLogger::class, $factory->getLogger()); } - public function testChangeChannelReturnsDifferentLogger(): void + public function testChangeLogChannelReturnsDifferentLogger(): void { $config = $this->createStub(IManageConfigValues::class); $config->method('get')->willReturnMap([ @@ -110,4 +111,26 @@ class LoggerManagerTest extends TestCase $this->assertNotSame($logger1, $factory->getLogger()); } + + public function testChangeLogChannelToWorkerReturnsWorkerLogger(): void + { + $config = $this->createStub(IManageConfigValues::class); + $config->method('get')->willReturnMap([ + ['system', 'debugging', null, false], + ['system', 'profiling', null, true], + ]); + + $reflectionProperty = new \ReflectionProperty(LoggerManager::class, 'logger'); + $reflectionProperty->setAccessible(true); + $reflectionProperty->setValue(null, null); + + $factory = new LoggerManager( + $config, + $this->createStub(LoggerFactory::class) + ); + + $factory->changeLogChannel(LogChannel::WORKER); + + $this->assertInstanceOf(WorkerLogger::class, $factory->getLogger()); + } }