Merge pull request #36641 from nextcloud/instrument-app-register

Add more profiler instrumentation to app loading
nextcloud · Feb 13, 2023 · 8e1403a · 8e1403a
2 parents 8f0849a + fe78ef7
commit 8e1403a
Show file tree

Hide file tree

Showing 2 changed files with 26 additions and 7 deletions.
diff --git a/lib/private/AppFramework/Bootstrap/Coordinator.php b/lib/private/AppFramework/Bootstrap/Coordinator.php
@@ -98,11 +98,14 @@ public function runLazyRegistration(string $appId): void {
 	 * @param string[] $appIds
 	 */
 	private function registerApps(array $appIds): void {
+		$this->eventLogger->start('bootstrap:register_apps', '');
 		if ($this->registrationContext === null) {
 			$this->registrationContext = new RegistrationContext($this->logger);
 		}
 		$apps = [];
 		foreach ($appIds as $appId) {
+			$this->eventLogger->start("bootstrap:register_app:$appId", "Register $appId");
+			$this->eventLogger->start("bootstrap:register_app:$appId:autoloader", "Setup autoloader for $appId");
 			/*
 			 * First, we have to enable the app's autoloader
 			 *
@@ -114,36 +117,43 @@ private function registerApps(array $appIds): void {
 				continue;
 			}
 			OC_App::registerAutoloading($appId, $path);
+			$this->eventLogger->end("bootstrap:register_app:$appId:autoloader");
 
 			/*
-			 * Next we check if there is an application class and it implements
+			 * Next we check if there is an application class, and it implements
 			 * the \OCP\AppFramework\Bootstrap\IBootstrap interface
 			 */
 			$appNameSpace = App::buildAppNamespace($appId);
 			$applicationClassName = $appNameSpace . '\\AppInfo\\Application';
 			try {
 				if (class_exists($applicationClassName) && in_array(IBootstrap::class, class_implements($applicationClassName), true)) {
+					$this->eventLogger->start("bootstrap:register_app:$appId:application", "Load `Application` instance for $appId");
 					try {
 						/** @var IBootstrap|App $application */
 						$apps[$appId] = $application = $this->serverContainer->query($applicationClassName);
 					} catch (QueryException $e) {
 						// Weird, but ok
+						$this->eventLogger->end("bootstrap:register_app:$appId");
 						continue;
 					}
+					$this->eventLogger->end("bootstrap:register_app:$appId:application");
 
-					$this->eventLogger->start('bootstrap:register_app_' . $appId, '');
+					$this->eventLogger->start("bootstrap:register_app:$appId:register", "`Application::register` for $appId");
 					$application->register($this->registrationContext->for($appId));
-					$this->eventLogger->end('bootstrap:register_app_' . $appId);
+					$this->eventLogger->end("bootstrap:register_app:$appId:register");
 				}
 			} catch (Throwable $e) {
 				$this->logger->emergency('Error during app service registration: ' . $e->getMessage(), [
 					'exception' => $e,
 					'app' => $appId,
 				]);
+				$this->eventLogger->end("bootstrap:register_app:$appId");
 				continue;
 			}
+			$this->eventLogger->end("bootstrap:register_app:$appId");
 		}
 
+		$this->eventLogger->start('bootstrap:register_apps:apply', 'Apply all the registered service by apps');
 		/**
 		 * Now that all register methods have been called, we can delegate the registrations
 		 * to the actual services
@@ -153,6 +163,8 @@ private function registerApps(array $appIds): void {
 		$this->registrationContext->delegateDashboardPanelRegistrations($this->dashboardManager);
 		$this->registrationContext->delegateEventListenerRegistrations($this->eventDispatcher);
 		$this->registrationContext->delegateContainerRegistrations($apps);
+		$this->eventLogger->end('bootstrap:register_apps:apply');
+		$this->eventLogger->end('bootstrap:register_apps');
 	}
 
 	public function getRegistrationContext(): ?RegistrationContext {
@@ -178,7 +190,7 @@ public function bootApp(string $appId): void {
 		 * the instance was already created for register, but any other
 		 * (legacy) code will now do their magic via the constructor.
 		 */
-		$this->eventLogger->start('bootstrap:boot_app_' . $appId, '');
+		$this->eventLogger->start('bootstrap:boot_app:' . $appId, "Call `Application::boot` for $appId");
 		try {
 			/** @var App $application */
 			$application = $this->serverContainer->query($applicationClassName);
@@ -196,7 +208,7 @@ public function bootApp(string $appId): void {
 				'exception' => $e,
 			]);
 		}
-		$this->eventLogger->end('bootstrap:boot_app_' . $appId);
+		$this->eventLogger->end('bootstrap:boot_app:' . $appId);
 	}
 
 	public function isBootable(string $appId) {

diff --git a/lib/private/legacy/OC_App.php b/lib/private/legacy/OC_App.php
@@ -167,6 +167,8 @@ public static function loadApp(string $app): void {
 		if ($appPath === false) {
 			return;
 		}
+		$eventLogger = \OC::$server->get(\OCP\Diagnostics\IEventLogger::class);
+		$eventLogger->start("bootstrap:load_app:$app", "Load $app");
 
 		// in case someone calls loadApp() directly
 		self::registerAutoloading($app, $appPath);
@@ -177,12 +179,12 @@ public static function loadApp(string $app): void {
 
 		$hasAppPhpFile = is_file($appPath . '/appinfo/app.php');
 
-		\OC::$server->getEventLogger()->start('bootstrap:load_app_' . $app, 'Load app: ' . $app);
 		if ($isBootable && $hasAppPhpFile) {
 			\OC::$server->getLogger()->error('/appinfo/app.php is not loaded when \OCP\AppFramework\Bootstrap\IBootstrap on the application class is used. Migrate everything from app.php to the Application class.', [
 				'app' => $app,
 			]);
 		} elseif ($hasAppPhpFile) {
+			$eventLogger->start("bootstrap:load_app:$app:app.php", "Load legacy app.php app $app");
 			\OC::$server->getLogger()->debug('/appinfo/app.php is deprecated, use \OCP\AppFramework\Bootstrap\IBootstrap on the application class instead.', [
 				'app' => $app,
 			]);
@@ -205,11 +207,12 @@ public static function loadApp(string $app): void {
 					]);
 				}
 			}
+			$eventLogger->end("bootstrap:load_app:$app:app.php");
 		}
-		\OC::$server->getEventLogger()->end('bootstrap:load_app_' . $app);
 
 		$coordinator->bootApp($app);
 
+		$eventLogger->start("bootstrap:load_app:$app:info", "Load info.xml for $app and register any services defined in it");
 		$info = self::getAppInfo($app);
 		if (!empty($info['activity']['filters'])) {
 			foreach ($info['activity']['filters'] as $filter) {
@@ -264,6 +267,10 @@ public static function loadApp(string $app): void {
 				}
 			}
 		}
+
+		$eventLogger->end("bootstrap:load_app:$app:info");
+
+		$eventLogger->end("bootstrap:load_app:$app");
 	}
 
 	/**