From cc89a2a2b82d468b8ca2f7ac03f4e9e011ab7bba Mon Sep 17 00:00:00 2001 From: Christoph Wurst Date: Tue, 23 Sep 2025 09:40:55 +0200 Subject: [PATCH] refactor: extract slow operation logging into trait Signed-off-by: Christoph Wurst --- lib/composer/composer/autoload_classmap.php | 1 + lib/composer/composer/autoload_static.php | 1 + lib/private/Diagnostics/TLogSlowOperation.php | 50 +++++++++++++++++++ lib/private/Session/Internal.php | 40 ++++++--------- 4 files changed, 67 insertions(+), 25 deletions(-) create mode 100644 lib/private/Diagnostics/TLogSlowOperation.php diff --git a/lib/composer/composer/autoload_classmap.php b/lib/composer/composer/autoload_classmap.php index aca39f64ddb..86592fdada5 100644 --- a/lib/composer/composer/autoload_classmap.php +++ b/lib/composer/composer/autoload_classmap.php @@ -1633,6 +1633,7 @@ return array( 'OC\\Diagnostics\\EventLogger' => $baseDir . '/lib/private/Diagnostics/EventLogger.php', 'OC\\Diagnostics\\Query' => $baseDir . '/lib/private/Diagnostics/Query.php', 'OC\\Diagnostics\\QueryLogger' => $baseDir . '/lib/private/Diagnostics/QueryLogger.php', + 'OC\\Diagnostics\\TLogSlowOperation' => $baseDir . '/lib/private/Diagnostics/TLogSlowOperation.php', 'OC\\DirectEditing\\Manager' => $baseDir . '/lib/private/DirectEditing/Manager.php', 'OC\\DirectEditing\\Token' => $baseDir . '/lib/private/DirectEditing/Token.php', 'OC\\EmojiHelper' => $baseDir . '/lib/private/EmojiHelper.php', diff --git a/lib/composer/composer/autoload_static.php b/lib/composer/composer/autoload_static.php index e486f075eed..fcd2f4eaee6 100644 --- a/lib/composer/composer/autoload_static.php +++ b/lib/composer/composer/autoload_static.php @@ -1674,6 +1674,7 @@ class ComposerStaticInit749170dad3f5e7f9ca158f5a9f04f6a2 'OC\\Diagnostics\\EventLogger' => __DIR__ . '/../../..' . '/lib/private/Diagnostics/EventLogger.php', 'OC\\Diagnostics\\Query' => __DIR__ . '/../../..' . '/lib/private/Diagnostics/Query.php', 'OC\\Diagnostics\\QueryLogger' => __DIR__ . '/../../..' . '/lib/private/Diagnostics/QueryLogger.php', + 'OC\\Diagnostics\\TLogSlowOperation' => __DIR__ . '/../../..' . '/lib/private/Diagnostics/TLogSlowOperation.php', 'OC\\DirectEditing\\Manager' => __DIR__ . '/../../..' . '/lib/private/DirectEditing/Manager.php', 'OC\\DirectEditing\\Token' => __DIR__ . '/../../..' . '/lib/private/DirectEditing/Token.php', 'OC\\EmojiHelper' => __DIR__ . '/../../..' . '/lib/private/EmojiHelper.php', diff --git a/lib/private/Diagnostics/TLogSlowOperation.php b/lib/private/Diagnostics/TLogSlowOperation.php new file mode 100644 index 00000000000..4ad728ca6e2 --- /dev/null +++ b/lib/private/Diagnostics/TLogSlowOperation.php @@ -0,0 +1,50 @@ + 0.1) { + $logLevel = match (true) { + $timeSpent > 25 => ILogger::ERROR, + $timeSpent > 10 => ILogger::WARN, + $timeSpent > 0.5 => ILogger::INFO, + default => ILogger::DEBUG, + }; + $logger->log( + $logLevel, + "Slow $operation detected", + [ + 'timeSpent' => $timeSpent, + ], + ); + } + return $result; + } + +} diff --git a/lib/private/Session/Internal.php b/lib/private/Session/Internal.php index b465bcd3eda..4f812af920b 100644 --- a/lib/private/Session/Internal.php +++ b/lib/private/Session/Internal.php @@ -10,6 +10,7 @@ declare(strict_types=1); namespace OC\Session; use OC\Authentication\Token\IProvider; +use OC\Diagnostics\TLogSlowOperation; use OCP\Authentication\Exceptions\InvalidTokenException; use OCP\ILogger; use OCP\Session\Exceptions\SessionNotAvailableException; @@ -25,6 +26,9 @@ use function microtime; * @package OC\Session */ class Internal extends Session { + + use TLogSlowOperation; + /** * @param string $name * @throws \Exception @@ -191,31 +195,17 @@ class Internal extends Session { */ private function invoke(string $functionName, array $parameters = [], bool $silence = false) { try { - $timeBefore = microtime(true); - if ($silence) { - $result = @call_user_func_array($functionName, $parameters); - } else { - $result = call_user_func_array($functionName, $parameters); - } - $timeAfter = microtime(true); - $timeSpent = $timeAfter - $timeBefore; - if ($timeSpent > 0.1) { - $logLevel = match (true) { - $timeSpent > 25 => ILogger::ERROR, - $timeSpent > 10 => ILogger::WARN, - $timeSpent > 0.5 => ILogger::INFO, - default => ILogger::DEBUG, - }; - $this->logger?->log( - $logLevel, - "Slow session operation $functionName detected", - [ - 'parameters' => $parameters, - 'timeSpent' => $timeSpent, - ], - ); - } - return $result; + return $this->monitorAndLog( + $this->logger, + $functionName, + function () use ($silence, $functionName, $parameters){ + if ($silence) { + return @call_user_func_array($functionName, $parameters); + } else { + return call_user_func_array($functionName, $parameters); + } + } + ); } catch (\Error $e) { $this->trapError($e->getCode(), $e->getMessage()); }