diff --git a/lib/composer/composer/autoload_classmap.php b/lib/composer/composer/autoload_classmap.php index ee77fbd4cda82..234548f8dfdd1 100644 --- a/lib/composer/composer/autoload_classmap.php +++ b/lib/composer/composer/autoload_classmap.php @@ -1602,6 +1602,7 @@ '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 3b18f00da9697..3ae80cdc593f9 100644 --- a/lib/composer/composer/autoload_static.php +++ b/lib/composer/composer/autoload_static.php @@ -1643,6 +1643,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 0000000000000..4ad728ca6e2e6 --- /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/Http/Client/DnsPinMiddleware.php b/lib/private/Http/Client/DnsPinMiddleware.php index 96e0f71adbe9a..b031f3f32366f 100644 --- a/lib/private/Http/Client/DnsPinMiddleware.php +++ b/lib/private/Http/Client/DnsPinMiddleware.php @@ -8,15 +8,20 @@ */ namespace OC\Http\Client; +use OC\Diagnostics\TLogSlowOperation; use OC\Net\IpAddressClassifier; use OCP\Http\Client\LocalServerException; use Psr\Http\Message\RequestInterface; +use Psr\Log\LoggerInterface; class DnsPinMiddleware { + use TLogSlowOperation; + public function __construct( private NegativeDnsCache $negativeDnsCache, private IpAddressClassifier $ipAddressClassifier, + private LoggerInterface $logger, ) { } @@ -88,7 +93,11 @@ private function dnsResolve(string $target, int $recursionCount) : array { * Wrapper for dns_get_record */ protected function dnsGetRecord(string $hostname, int $type): array|false { - return \dns_get_record($hostname, $type); + return $this->monitorAndLog( + $this->logger, + 'dns_get_record', + fn () => \dns_get_record($hostname, $type), + ); } public function addDnsPinning(): callable { diff --git a/lib/private/Session/Internal.php b/lib/private/Session/Internal.php index b465bcd3edadb..ece5ba61b5da3 100644 --- a/lib/private/Session/Internal.php +++ b/lib/private/Session/Internal.php @@ -10,12 +10,11 @@ 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; use Psr\Log\LoggerInterface; use function call_user_func_array; -use function microtime; /** * Class Internal @@ -25,6 +24,9 @@ * @package OC\Session */ class Internal extends Session { + + use TLogSlowOperation; + /** * @param string $name * @throws \Exception @@ -191,31 +193,17 @@ public function trapError(int $errorNumber, string $errorString) { */ 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()); } diff --git a/tests/lib/Http/Client/DnsPinMiddlewareTest.php b/tests/lib/Http/Client/DnsPinMiddlewareTest.php index 9c0aa198cd8e2..790206a94220a 100644 --- a/tests/lib/Http/Client/DnsPinMiddlewareTest.php +++ b/tests/lib/Http/Client/DnsPinMiddlewareTest.php @@ -20,6 +20,7 @@ use OCP\Http\Client\LocalServerException; use OCP\ICacheFactory; use Psr\Http\Message\RequestInterface; +use Psr\Log\NullLogger; use Test\TestCase; class DnsPinMiddlewareTest extends TestCase { @@ -35,9 +36,10 @@ protected function setUp(): void { $ipAddressClassifier = new IpAddressClassifier(); $negativeDnsCache = new NegativeDnsCache($cacheFactory); + $logger = new NullLogger(); $this->dnsPinMiddleware = $this->getMockBuilder(DnsPinMiddleware::class) - ->setConstructorArgs([$negativeDnsCache, $ipAddressClassifier]) + ->setConstructorArgs([$negativeDnsCache, $ipAddressClassifier, $logger]) ->onlyMethods(['dnsGetRecord']) ->getMock(); }