more routing performance instrumentation

lib/private/AppFramework/App.php

@@ -34,7 +34,6 @@
 use OC\AppFramework\DependencyInjection\DIContainer;
 use OC\AppFramework\Http\Dispatcher;
 use OC\AppFramework\Http\Request;
-use OC\Diagnostics\EventLogger;
 use OCP\Profiler\IProfiler;
 use OC\Profiler\RoutingDataCollector;
 use OCP\AppFramework\QueryException;
@@ -43,7 +42,6 @@
 use OCP\AppFramework\Http\IOutput;
 use OCP\Diagnostics\IEventLogger;
 use OCP\HintException;
-use OCP\IConfig;
 use OCP\IRequest;
 
 /**
@@ -120,14 +118,16 @@ public static function getAppIdForClass(string $className, string $topNamespace
 	public static function main(string $controllerName, string $methodName, DIContainer $container, array $urlParams = null) {
 		/** @var IProfiler $profiler */
 		$profiler = $container->get(IProfiler::class);
-		$config = $container->get(IConfig::class);
+		$eventLogger = $container->get(IEventLogger::class);
 		// Disable profiler on the profiler UI
 		$profiler->setEnabled($profiler->isEnabled() && !is_null($urlParams) && isset($urlParams['_route']) && !str_starts_with($urlParams['_route'], 'profiler.'));
 		if ($profiler->isEnabled()) {
 			\OC::$server->get(IEventLogger::class)->activate();
 			$profiler->add(new RoutingDataCollector($container['AppName'], $controllerName, $methodName));
 		}
 
+		$eventLogger->start('app:controller:params', 'Gather controller parameters');
+
 		if (!is_null($urlParams)) {
 			/** @var Request $request */
 			$request = $container->get(IRequest::class);
@@ -139,6 +139,10 @@ public static function main(string $controllerName, string $methodName, DIContai
 		}
 		$appName = $container['AppName'];
 
+		$eventLogger->end('app:controller:params');
+
+		$eventLogger->start('app:controller:load', 'Load app controller');
+
 		// first try $controllerName then go for \OCA\AppName\Controller\$controllerName
 		try {
 			$controller = $container->get($controllerName);
@@ -158,10 +162,18 @@ public static function main(string $controllerName, string $methodName, DIContai
 			$controller = $container->query($controllerName);
 		}
 
+		$eventLogger->end('app:controller:load');
+
+		$eventLogger->start('app:controller:dispatcher', 'Initialize dispatcher and pre-middleware');
+
 		// initialize the dispatcher and run all the middleware before the controller
 		/** @var Dispatcher $dispatcher */
 		$dispatcher = $container['Dispatcher'];
 
+		$eventLogger->end('app:controller:dispatcher');
+
+		$eventLogger->start('app:controller:run', 'Run app controller');
+
 		[
 			$httpHeaders,
 			$responseHeaders,
@@ -170,11 +182,11 @@ public static function main(string $controllerName, string $methodName, DIContai
 			$response
 		] = $dispatcher->dispatch($controller, $methodName);
 
+		$eventLogger->end('app:controller:run');
+
 		$io = $container[IOutput::class];
 
 		if ($profiler->isEnabled()) {
-			/** @var EventLogger $eventLogger */
-			$eventLogger = $container->get(IEventLogger::class);
 			$eventLogger->end('runtime');
 			$profile = $profiler->collect($container->get(IRequest::class), $response);
 			$profiler->saveProfile($profile);

lib/private/Route/CachingRouter.php

@@ -24,20 +24,27 @@
  */
 namespace OC\Route;
 
+use OCP\Diagnostics\IEventLogger;
+use OCP\ICache;
+use OCP\ICacheFactory;
+use OCP\IConfig;
+use OCP\IRequest;
+use Psr\Container\ContainerInterface;
 use Psr\Log\LoggerInterface;
 
 class CachingRouter extends Router {
-	/**
-	 * @var \OCP\ICache
-	 */
-	protected $cache;
+	protected ICache $cache;
 
-	/**
-	 * @param \OCP\ICache $cache
-	 */
-	public function __construct($cache, LoggerInterface $logger) {
-		$this->cache = $cache;
-		parent::__construct($logger);
+	public function __construct(
+		ICacheFactory $cacheFactory,
+		LoggerInterface $logger,
+		IRequest $request,
+		IConfig $config,
+		IEventLogger $eventLogger,
+		ContainerInterface $container
+	) {
+		$this->cache = $cacheFactory->createLocal('route');
+		parent::__construct($logger, $request, $config, $eventLogger, $container);
 	}
 
 	/**

lib/private/Route/Router.php

@@ -34,8 +34,12 @@
 
 use OC\AppFramework\Routing\RouteParser;
 use OCP\AppFramework\App;
+use OCP\Diagnostics\IEventLogger;
+use OCP\IConfig;
+use OCP\IRequest;
 use OCP\Route\IRouter;
 use OCP\Util;
+use Psr\Container\ContainerInterface;
 use Psr\Log\LoggerInterface;
 use Symfony\Component\Routing\Exception\ResourceNotFoundException;
 use Symfony\Component\Routing\Exception\RouteNotFoundException;
@@ -64,24 +68,35 @@ class Router implements IRouter {
 	protected LoggerInterface $logger;
 	/** @var RequestContext */
 	protected $context;
-
-	public function __construct(LoggerInterface $logger) {
+	private IEventLogger $eventLogger;
+	private IConfig $config;
+	private ContainerInterface $container;
+
+	public function __construct(
+		LoggerInterface $logger,
+		IRequest $request,
+		IConfig $config,
+		IEventLogger $eventLogger,
+		ContainerInterface $container
+	) {
 		$this->logger = $logger;
+		$this->config = $config;
 		$baseUrl = \OC::$WEBROOT;
-		if (!(\OC::$server->getConfig()->getSystemValue('htaccess.IgnoreFrontController', false) === true || getenv('front_controller_active') === 'true')) {
+		if (!($config->getSystemValue('htaccess.IgnoreFrontController', false) === true || getenv('front_controller_active') === 'true')) {
 			$baseUrl .= '/index.php';
 		}
 		if (!\OC::$CLI && isset($_SERVER['REQUEST_METHOD'])) {
 			$method = $_SERVER['REQUEST_METHOD'];
 		} else {
 			$method = 'GET';
 		}
-		$request = \OC::$server->getRequest();
 		$host = $request->getServerHost();
 		$schema = $request->getServerProtocol();
 		$this->context = new RequestContext($baseUrl, $method, $host, $schema);
 		// TODO cache
 		$this->root = $this->getCollection('root');
+		$this->eventLogger = $eventLogger;
+		$this->container = $container;
 	}
 
 	/**
@@ -134,7 +149,7 @@ public function loadRoutes($app = null) {
 				$routingFiles = [];
 			}
 		}
-		\OC::$server->getEventLogger()->start('loadroutes' . $requestedApp, 'Loading Routes');
+		$this->eventLogger->start('route:load:' . $requestedApp, 'Loading Routes for ' . $requestedApp);
 		foreach ($routingFiles as $app => $file) {
 			if (!isset($this->loadedApps[$app])) {
 				if (!\OC_App::isAppLoaded($app)) {
@@ -170,7 +185,7 @@ public function loadRoutes($app = null) {
 			$collection->addPrefix('/ocs');
 			$this->root->addCollection($collection);
 		}
-		\OC::$server->getEventLogger()->end('loadroutes' . $requestedApp);
+		$this->eventLogger->end('route:load:' . $requestedApp);
 	}
 
 	/**
@@ -231,6 +246,7 @@ public function create($name,
 	 * @return array
 	 */
 	public function findMatchingRoute(string $url): array {
+		$this->eventLogger->start('route:match', 'Match route');
 		if (substr($url, 0, 6) === '/apps/') {
 			// empty string / 'apps' / $app / rest of the route
 			[, , $app,] = explode('/', $url, 4);
@@ -249,7 +265,7 @@ public function findMatchingRoute(string $url): array {
 			$this->loadRoutes('settings');
 		} elseif (substr($url, 0, 6) === '/core/') {
 			\OC::$REQUESTEDAPP = $url;
-			if (!\OC::$server->getConfig()->getSystemValueBool('maintenance') && !Util::needUpgrade()) {
+			if (!$this->config->getSystemValueBool('maintenance') && !Util::needUpgrade()) {
 				\OC_App::loadApps();
 			}
 			$this->loadRoutes('core');
@@ -276,6 +292,7 @@ public function findMatchingRoute(string $url): array {
 			}
 		}
 
+		$this->eventLogger->end('route:match');
 		return $parameters;
 	}
 
@@ -289,7 +306,7 @@ public function findMatchingRoute(string $url): array {
 	public function match($url) {
 		$parameters = $this->findMatchingRoute($url);
 
-		\OC::$server->getEventLogger()->start('run_route', 'Run route');
+		$this->eventLogger->start('route:run', 'Run route');
 		if (isset($parameters['caller'])) {
 			$caller = $parameters['caller'];
 			unset($parameters['caller']);
@@ -303,13 +320,15 @@ public function match($url) {
 			}
 			unset($parameters['action']);
 			unset($parameters['caller']);
+			$this->eventLogger->start('route:run:call', 'Run callable route');
 			call_user_func($action, $parameters);
+			$this->eventLogger->end('route:run:call');
 		} elseif (isset($parameters['file'])) {
 			include $parameters['file'];
 		} else {
 			throw new \Exception('no action available');
 		}
-		\OC::$server->getEventLogger()->end('run_route');
+		$this->eventLogger->end('route:run');
 	}
 
 	/**
@@ -434,7 +453,7 @@ private function getApplicationClass(string $appName) {
 		$applicationClassName = $appNameSpace . '\\AppInfo\\Application';
 
 		if (class_exists($applicationClassName)) {
-			$application = \OC::$server->query($applicationClassName);
+			$application = $this->container->get($applicationClassName);
 		} else {
 			$application = new App($appName);
 		}

lib/private/Server.php

@@ -129,6 +129,7 @@
 use OC\Remote\Api\ApiFactory;
 use OC\Remote\InstanceFactory;
 use OC\RichObjectStrings\Validator;
+use OC\Route\CachingRouter;
 use OC\Route\Router;
 use OC\Security\Bruteforce\Throttler;
 use OC\Security\CertificateManager;
@@ -819,11 +820,10 @@ public function __construct($webRoot, \OC\Config $config) {
 
 		$this->registerService(Router::class, function (Server $c) {
 			$cacheFactory = $c->get(ICacheFactory::class);
-			$logger = $c->get(LoggerInterface::class);
 			if ($cacheFactory->isLocalCacheAvailable()) {
-				$router = new \OC\Route\CachingRouter($cacheFactory->createLocal('route'), $logger);
+				$router = $c->resolve(CachingRouter::class);
 			} else {
-				$router = new \OC\Route\Router($logger);
+				$router = $c->resolve(Router::class);
 			}
 			return $router;
 		});

tests/lib/AppFramework/Routing/RoutingTest.php

@@ -6,8 +6,12 @@
 use OC\AppFramework\Routing\RouteConfig;
 use OC\Route\Route;
 use OC\Route\Router;
+use OCP\Diagnostics\IEventLogger;
+use OCP\IConfig;
+use OCP\IRequest;
 use OCP\Route\IRouter;
 use PHPUnit\Framework\MockObject\MockObject;
+use Psr\Container\ContainerInterface;
 use Psr\Log\LoggerInterface;
 
 class RoutingTest extends \Test\TestCase {
@@ -133,7 +137,13 @@ public function testSimpleRouteWithBrokenName() {
 		/** @var IRouter|MockObject $router */
 		$router = $this->getMockBuilder(Router::class)
 			->onlyMethods(['create'])
-			->setConstructorArgs([$this->createMock(LoggerInterface::class)])
+			->setConstructorArgs([
+				$this->createMock(LoggerInterface::class),
+				$this->createMock(IRequest::class),
+				$this->createMock(IConfig::class),
+				$this->createMock(IEventLogger::class),
+				$this->createMock(ContainerInterface::class)
+			])
 			->getMock();
 
 		// load route configuration
@@ -154,7 +164,13 @@ public function testSimpleOCSRouteWithBrokenName() {
 		/** @var IRouter|MockObject $router */
 		$router = $this->getMockBuilder(Router::class)
 			->onlyMethods(['create'])
-			->setConstructorArgs([$this->createMock(LoggerInterface::class)])
+			->setConstructorArgs([
+				$this->createMock(LoggerInterface::class),
+				$this->createMock(IRequest::class),
+				$this->createMock(IConfig::class),
+				$this->createMock(IEventLogger::class),
+				$this->createMock(ContainerInterface::class)
+			])
 			->getMock();
 
 		// load route configuration
@@ -214,7 +230,13 @@ private function assertSimpleRoute($routes, $name, $verb, $url, $controllerName,
 		/** @var IRouter|MockObject $router */
 		$router = $this->getMockBuilder(Router::class)
 			->onlyMethods(['create'])
-			->setConstructorArgs([$this->createMock(LoggerInterface::class)])
+			->setConstructorArgs([
+				$this->createMock(LoggerInterface::class),
+				$this->createMock(IRequest::class),
+				$this->createMock(IConfig::class),
+				$this->createMock(IEventLogger::class),
+				$this->createMock(ContainerInterface::class)
+			])
 			->getMock();
 
 		// we expect create to be called once:
@@ -264,7 +286,13 @@ private function assertSimpleOCSRoute($routes,
 		/** @var IRouter|MockObject $router */
 		$router = $this->getMockBuilder(Router::class)
 			->onlyMethods(['create'])
-			->setConstructorArgs([$this->createMock(LoggerInterface::class)])
+			->setConstructorArgs([
+				$this->createMock(LoggerInterface::class),
+				$this->createMock(IRequest::class),
+				$this->createMock(IConfig::class),
+				$this->createMock(IEventLogger::class),
+				$this->createMock(ContainerInterface::class)
+			])
 			->getMock();
 
 		// we expect create to be called once:
@@ -291,7 +319,13 @@ private function assertOCSResource($yaml, $resourceName, $url, $controllerName,
 		/** @var IRouter|MockObject $router */
 		$router = $this->getMockBuilder(Router::class)
 			->onlyMethods(['create'])
-			->setConstructorArgs([$this->createMock(LoggerInterface::class)])
+			->setConstructorArgs([
+				$this->createMock(LoggerInterface::class),
+				$this->createMock(IRequest::class),
+				$this->createMock(IConfig::class),
+				$this->createMock(IEventLogger::class),
+				$this->createMock(ContainerInterface::class)
+			])
 			->getMock();
 
 		// route mocks
@@ -338,7 +372,13 @@ private function assertResource($yaml, $resourceName, $url, $controllerName, $pa
 		/** @var IRouter|MockObject $router */
 		$router = $this->getMockBuilder(Router::class)
 			->onlyMethods(['create'])
-			->setConstructorArgs([$this->createMock(LoggerInterface::class)])
+			->setConstructorArgs([
+				$this->createMock(LoggerInterface::class),
+				$this->createMock(IRequest::class),
+				$this->createMock(IConfig::class),
+				$this->createMock(IEventLogger::class),
+				$this->createMock(ContainerInterface::class)
+			])
 			->getMock();
 
 		// route mocks

tests/lib/Route/RouterTest.php

@@ -24,6 +24,10 @@
 namespace Test\Route;
 
 use OC\Route\Router;
+use OCP\Diagnostics\IEventLogger;
+use OCP\IConfig;
+use OCP\IRequest;
+use Psr\Container\ContainerInterface;
 use Psr\Log\LoggerInterface;
 use Test\TestCase;
 
@@ -44,7 +48,13 @@ function (string $message, array $data) {
 					$this->fail('Unexpected info log: '.(string)($data['exception'] ?? $message));
 				}
 			);
-		$router = new Router($logger);
+		$router = new Router(
+			$logger,
+			$this->createMock(IRequest::class),
+			$this->createMock(IConfig::class),
+			$this->createMock(IEventLogger::class),
+			$this->createMock(ContainerInterface::class),
+		);
 
 		$this->assertEquals('/index.php/apps/files/', $router->generate('files.view.index'));