perf: log slow DNS operations

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',

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',

lib/private/Diagnostics/TLogSlowOperation.php

@@ -0,0 +1,50 @@
+<?php
+
+declare(strict_types=1);
+
+/**
+ * SPDX-FileCopyrightText: 2025 Nextcloud GmbH and Nextcloud contributors
+ * SPDX-License-Identifier: AGPL-3.0-only
+ */
+
+namespace OC\Diagnostics;
+
+use OCP\ILogger;
+use Psr\Log\LoggerInterface;
+use function microtime;
+
+trait TLogSlowOperation {
+
+	/**
+	 * @template R
+	 * @param LoggerInterface $logger
+	 * @param string $operation
+	 * @param callable $fn
+	 * @psalm-param callable(): R $fn
+	 *
+	 * @return mixed
+	 */
+	public function monitorAndLog(LoggerInterface $logger, string $operation, callable $fn): mixed {
+		$timeBefore = microtime(true);
+		$result = $fn();
+		$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,
+			};
+			$logger->log(
+				$logLevel,
+				"Slow $operation detected",
+				[
+					'timeSpent' => $timeSpent,
+				],
+			);
+		}
+		return $result;
+	}
+
+}

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 {

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

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