Add support for WorkerLogger decorator in LoggerManager, deprecate core Logger class, deprecate DI::workerLogger()

This commit is contained in:
Art4 2025-01-12 08:21:30 +00:00
parent 0804413c41
commit 510f4e02c8
5 changed files with 76 additions and 21 deletions

View file

@ -13,6 +13,8 @@ use Psr\Log\LoggerInterface;
/** /**
* Logger functions * Logger functions
*
* @deprecated 2025.02 Use constructor injection or `DI::logger()` instead
*/ */
class Logger class Logger
{ {
@ -48,6 +50,8 @@ class Logger
/** /**
* Enable additional logging for worker usage * Enable additional logging for worker usage
* *
* @deprecated
*
* @param string $functionName The worker function, which got called * @param string $functionName The worker function, which got called
* *
* @throws \Friendica\Network\HTTPException\InternalServerErrorException * @throws \Friendica\Network\HTTPException\InternalServerErrorException
@ -60,6 +64,8 @@ class Logger
/** /**
* Disable additional logging for worker usage * Disable additional logging for worker usage
*
* @deprecated
*/ */
public static function disableWorker() public static function disableWorker()
{ {

View file

@ -13,6 +13,7 @@ use Friendica\Core\Config\Capability\IManageConfigValues;
use Friendica\Core\Logger\Capability\LogChannel; use Friendica\Core\Logger\Capability\LogChannel;
use Friendica\Core\Logger\Factory\LoggerFactory; use Friendica\Core\Logger\Factory\LoggerFactory;
use Friendica\Core\Logger\Type\ProfilerLogger; use Friendica\Core\Logger\Type\ProfilerLogger;
use Friendica\Core\Logger\Type\WorkerLogger;
use Friendica\Util\Profiler; use Friendica\Util\Profiler;
use Psr\Log\LoggerInterface; use Psr\Log\LoggerInterface;
use Psr\Log\LogLevel; use Psr\Log\LogLevel;
@ -31,6 +32,14 @@ final class LoggerManager
*/ */
private static $logger = null; 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 IManageConfigValues $config;
private LoggerFactory $factory; private LoggerFactory $factory;
@ -41,8 +50,6 @@ final class LoggerManager
private bool $profiling; private bool $profiling;
private string $logChannel;
public function __construct(IManageConfigValues $config, LoggerFactory $factory) public function __construct(IManageConfigValues $config, LoggerFactory $factory)
{ {
$this->config = $config; $this->config = $config;
@ -51,14 +58,12 @@ final class LoggerManager
$this->debug = (bool) $config->get('system', 'debugging') ?? false; $this->debug = (bool) $config->get('system', 'debugging') ?? false;
$this->logLevel = (string) $config->get('system', 'loglevel') ?? LogLevel::NOTICE; $this->logLevel = (string) $config->get('system', 'loglevel') ?? LogLevel::NOTICE;
$this->profiling = (bool) $config->get('system', 'profiling') ?? false; $this->profiling = (bool) $config->get('system', 'profiling') ?? false;
$this->logChannel = LogChannel::DEFAULT;
} }
public function changeLogChannel(string $logChannel): void public function changeLogChannel(string $logChannel): void
{ {
$this->logChannel = $logChannel; self::$logChannel = $logChannel;
self::$logger = null;
self::$logger = null;
} }
/** /**
@ -67,19 +72,19 @@ final class LoggerManager
public function getLogger(): LoggerInterface public function getLogger(): LoggerInterface
{ {
if (self::$logger === null) { if (self::$logger === null) {
self::$logger = $this->createProfiledLogger(); self::$logger = $this->createLogger();
} }
return self::$logger; return self::$logger;
} }
private function createProfiledLogger(): LoggerInterface private function createLogger(): LoggerInterface
{ {
// Always create NullLogger if debug is disabled // Always create NullLogger if debug is disabled
if ($this->debug === false) { if ($this->debug === false) {
$logger = new NullLogger(); $logger = new NullLogger();
} else { } else {
$logger = $this->factory->createLogger($this->logLevel, $this->logChannel); $logger = $this->factory->createLogger($this->logLevel, self::$logChannel);
} }
if ($this->profiling === true) { if ($this->profiling === true) {
@ -88,6 +93,11 @@ final class LoggerManager
$logger = new ProfilerLogger($logger, $profiler); $logger = new ProfilerLogger($logger, $profiler);
} }
// Decorate Logger as WorkerLogger for BC
if (self::$logChannel === LogChannel::WORKER) {
$logger = new WorkerLogger($logger);
}
return $logger; return $logger;
} }
} }

View file

@ -8,6 +8,8 @@
namespace Friendica\Core; namespace Friendica\Core;
use Friendica\Core\Cache\Enum\Duration; 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\Core\Worker\Entity\Process;
use Friendica\Database\DBA; use Friendica\Database\DBA;
use Friendica\DI; use Friendica\DI;
@ -537,9 +539,15 @@ class Worker
self::coolDown(); 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); $stamp = (float)microtime(true);
@ -559,19 +567,19 @@ class Worker
try { try {
call_user_func_array(sprintf('Friendica\Worker\%s::execute', $funcname), $argv); call_user_func_array(sprintf('Friendica\Worker\%s::execute', $funcname), $argv);
} catch (\Throwable $e) { } 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(); Worker::defer();
} }
} else { } else {
try { try {
$funcname($argv, count($argv)); $funcname($argv, count($argv));
} catch (\Throwable $e) { } 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(); Worker::defer();
} }
} }
Logger::disableWorker(); DI::loggerManager()->changeLogChannel(LogChannel::DEFAULT);
$appHelper->setQueue([]); $appHelper->setQueue([]);
@ -591,7 +599,7 @@ class Worker
$rest = round(max(0, $up_duration - (self::$db_duration + self::$lock_duration)), 2); $rest = round(max(0, $up_duration - (self::$db_duration + self::$lock_duration)), 2);
$exec = round($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(); self::coolDown();
@ -603,16 +611,16 @@ class Worker
self::$lock_duration = 0; self::$lock_duration = 0;
if ($duration > 3600) { 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) { } 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) { } 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) { } 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); DI::profiler()->saveLog(DI::logger(), 'ID ' . $queue['id'] . ': ' . $funcname);
} }

View file

@ -9,6 +9,7 @@ namespace Friendica;
use Dice\Dice; use Dice\Dice;
use Friendica\Core\Logger\Capability\ICheckLoggerSettings; use Friendica\Core\Logger\Capability\ICheckLoggerSettings;
use Friendica\Core\Logger\LoggerManager;
use Friendica\Core\Logger\Util\LoggerSettingsCheck; use Friendica\Core\Logger\Util\LoggerSettingsCheck;
use Friendica\Core\Session\Capability\IHandleSessions; use Friendica\Core\Session\Capability\IHandleSessions;
use Friendica\Core\Session\Capability\IHandleUserSessions; 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 * @return \Friendica\Core\Logger\Type\WorkerLogger
*/ */
public static function workerLogger() public static function workerLogger()
@ -331,6 +334,11 @@ abstract class DI
return self::$dice->create(Core\Logger\Type\WorkerLogger::class); return self::$dice->create(Core\Logger\Type\WorkerLogger::class);
} }
public static function loggerManager(): LoggerManager
{
return self::$dice->create(LoggerManager::class);
}
// //
// "Factory" namespace instances // "Factory" namespace instances
// //

View file

@ -14,6 +14,7 @@ use Friendica\Core\Logger\Capability\LogChannel;
use Friendica\Core\Logger\Factory\LoggerFactory; use Friendica\Core\Logger\Factory\LoggerFactory;
use Friendica\Core\Logger\LoggerManager; use Friendica\Core\Logger\LoggerManager;
use Friendica\Core\Logger\Type\ProfilerLogger; use Friendica\Core\Logger\Type\ProfilerLogger;
use Friendica\Core\Logger\Type\WorkerLogger;
use PHPUnit\Framework\TestCase; use PHPUnit\Framework\TestCase;
use Psr\Log\LoggerInterface; use Psr\Log\LoggerInterface;
use Psr\Log\NullLogger; use Psr\Log\NullLogger;
@ -87,7 +88,7 @@ class LoggerManagerTest extends TestCase
$this->assertInstanceOf(ProfilerLogger::class, $factory->getLogger()); $this->assertInstanceOf(ProfilerLogger::class, $factory->getLogger());
} }
public function testChangeChannelReturnsDifferentLogger(): void public function testChangeLogChannelReturnsDifferentLogger(): void
{ {
$config = $this->createStub(IManageConfigValues::class); $config = $this->createStub(IManageConfigValues::class);
$config->method('get')->willReturnMap([ $config->method('get')->willReturnMap([
@ -110,4 +111,26 @@ class LoggerManagerTest extends TestCase
$this->assertNotSame($logger1, $factory->getLogger()); $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());
}
} }