Merge pull request #9643 from annando/profiler

Improved performance profiler

index.php

@@ -21,6 +21,8 @@
 
 use Dice\Dice;
 
+$start_time = microtime(true);
+
 if (!file_exists(__DIR__ . '/vendor/autoload.php')) {
 	die('Vendor path not found. Please execute "bin/composer.phar --no-dev install" on the command line in the web root.');
 }
@@ -39,5 +41,6 @@ $a->runFrontend(
 	$dice->create(\Friendica\App\Router::class),
 	$dice->create(\Friendica\Core\PConfig\IPConfig::class),
 	$dice->create(\Friendica\Security\Authentication::class),
-	$dice->create(\Friendica\App\Page::class)
+	$dice->create(\Friendica\App\Page::class),
+	$start_time
 );

src/App.php

@@ -415,8 +415,11 @@ class App
 	 * @throws HTTPException\InternalServerErrorException
 	 * @throws \ImagickException
 	 */
-	public function runFrontend(App\Module $module, App\Router $router, IPConfig $pconfig, Authentication $auth, App\Page $page)
+	public function runFrontend(App\Module $module, App\Router $router, IPConfig $pconfig, Authentication $auth, App\Page $page, float $start_time)
 	{
+		$this->profiler->set($start_time, 'start');
+		$this->profiler->set(microtime(true), 'classinit');
+
 		$moduleName = $module->getName();
 
 		try {
@@ -551,12 +554,12 @@ class App
 			$module = $module->determineClass($this->args, $router, $this->config);
 
 			// Let the module run it's internal process (init, get, post, ...)
-			$module->run($this->l10n, $this->baseURL, $this->logger, $_SERVER, $_POST);
+			$module->run($this->l10n, $this->baseURL, $this->logger, $this->profiler, $_SERVER, $_POST);
 		} catch (HTTPException $e) {
 			ModuleHTTPException::rawContent($e);
 		}
 
-		$page->run($this, $this->baseURL, $this->mode, $module, $this->l10n, $this->config, $pconfig);
+		$page->run($this, $this->baseURL, $this->mode, $module, $this->l10n, $this->profiler, $this->config, $pconfig);
 	}
 
 	/**

src/App/Module.php

@@ -30,6 +30,7 @@ use Friendica\Module\HTTPException\MethodNotAllowed;
 use Friendica\Module\HTTPException\PageNotFound;
 use Friendica\Network\HTTPException\MethodNotAllowedException;
 use Friendica\Network\HTTPException\NotFoundException;
+use Friendica\Util\Profiler;
 use Psr\Log\LoggerInterface;
 
 /**
@@ -234,7 +235,7 @@ class Module
 	 *
 	 * @throws \Friendica\Network\HTTPException\InternalServerErrorException
 	 */
-	public function run(Core\L10n $l10n, App\BaseURL $baseUrl, LoggerInterface $logger, array $server, array $post)
+	public function run(Core\L10n $l10n, App\BaseURL $baseUrl, LoggerInterface $logger, Profiler $profiler, array $server, array $post)
 	{
 		if ($this->printNotAllowedAddon) {
 			notice($l10n->t("You must be logged in to use addons. "));
@@ -266,10 +267,15 @@ class Module
 
 		$placeholder = '';
 
+		$profiler->set(microtime(true), 'ready');
+		$timestamp = microtime(true);
+
 		Core\Hook::callAll($this->module . '_mod_init', $placeholder);
 
 		call_user_func([$this->module_class, 'init'], $this->module_parameters);
 
+		$profiler->set(microtime(true) - $timestamp, 'init');
+
 		if ($server['REQUEST_METHOD'] === 'POST') {
 			Core\Hook::callAll($this->module . '_mod_post', $post);
 			call_user_func([$this->module_class, 'post'], $this->module_parameters);

src/App/Page.php

@@ -36,6 +36,7 @@ use Friendica\Module\Special\HTTPException as ModuleHTTPException;
 use Friendica\Network\HTTPException;
 use Friendica\Util\Network;
 use Friendica\Util\Strings;
+use Friendica\Util\Profiler;
 
 /**
  * Contains the page specific environment variables for the current Page
@@ -375,7 +376,7 @@ class Page implements ArrayAccess
 	 *
 	 * @throws HTTPException\InternalServerErrorException
 	 */
-	public function run(App $app, BaseURL $baseURL, Mode $mode, Module $module, L10n $l10n, IConfig $config, IPConfig $pconfig)
+	public function run(App $app, BaseURL $baseURL, Mode $mode, Module $module, L10n $l10n, Profiler $profiler, IConfig $config, IPConfig $pconfig)
 	{
 		$moduleName = $module->getName();
 
@@ -384,7 +385,9 @@ class Page implements ArrayAccess
 		 *
 		 * Sets the $Page->page['content'] variable
 		 */
+		$timestamp = microtime(true);
 		$this->initContent($module, $mode);
+		$profiler->set(microtime(true) - $timestamp, 'content');
 
 		// Load current theme info after module has been initialized as theme could have been set in module
 		$currentTheme = $app->getCurrentTheme();

src/Util/Profiler.php

@@ -135,6 +135,7 @@ class Profiler implements ContainerInterface
 	{
 		$this->performance = [];
 		$this->performance['start'] = microtime(true);
+		$this->performance['ready'] = 0;
 		$this->performance['database'] = 0;
 		$this->performance['database_write'] = 0;
 		$this->performance['cache'] = 0;
@@ -145,6 +146,10 @@ class Profiler implements ContainerInterface
 		$this->performance['parser'] = 0;
 		$this->performance['marktime'] = 0;
 		$this->performance['marktime'] = microtime(true);
+		$this->performance['classcreate'] = 0;
+		$this->performance['classinit'] = 0;
+		$this->performance['init'] = 0;
+		$this->performance['content'] = 0;
 	}
 
 	/**
@@ -277,6 +282,11 @@ class Profiler implements ContainerInterface
 		}
 	}
 
+	public function set($timestamp, $id)
+	{
+		$this->performance[$id] = $timestamp;
+	}
+
 	/**
 	 * Returns true if the container can return an entry for the given identifier.
 	 * Returns false otherwise.