Merge pull request #11528 from annando/logruntime

Log the execution time

mod/fbrowser.php

@@ -39,11 +39,11 @@ use Friendica\Util\Strings;
 function fbrowser_content(App $a)
 {
 	if (!local_user()) {
-		exit();
+		System::exit();
 	}
 
 	if (DI::args()->getArgc() == 1) {
-		exit();
+		System::exit();
 	}
 
 	// Needed to match the correct template in a module that uses a different theme than the user/site/default

mod/photos.php

@@ -158,7 +158,7 @@ function photos_post(App $a)
 
 	if (!$can_post) {
 		notice(DI::l10n()->t('Permission denied.'));
-		exit();
+		System::exit();
 	}
 
 	$owner_record = User::getOwnerDataById($page_owner_uid);
@@ -166,7 +166,7 @@ function photos_post(App $a)
 	if (!$owner_record) {
 		notice(DI::l10n()->t('Contact information unavailable'));
 		DI::logger()->info('photos_post: unable to locate contact record for page owner. uid=' . $page_owner_uid);
-		exit();
+		System::exit();
 	}
 
 	$aclFormatter = DI::aclFormatter();

mod/pubsub.php

@@ -22,6 +22,7 @@
 use Friendica\App;
 use Friendica\Core\Logger;
 use Friendica\Core\Protocol;
+use Friendica\Core\System;
 use Friendica\Database\DBA;
 use Friendica\DI;
 use Friendica\Model\Contact;
@@ -38,7 +39,7 @@ function hub_return($valid, $body)
 	} else {
 		throw new \Friendica\Network\HTTPException\NotFoundException();
 	}
-	exit();
+	System::exit();
 }
 
 // when receiving an XML feed, always return OK

mod/pubsubhubbub.php

@@ -21,6 +21,7 @@
 
 use Friendica\App;
 use Friendica\Core\Logger;
+use Friendica\Core\System;
 use Friendica\Database\DBA;
 use Friendica\DI;
 use Friendica\Model\PushSubscriber;
@@ -142,5 +143,5 @@ function pubsubhubbub_init(App $a) {
 
 		throw new \Friendica\Network\HTTPException\AcceptedException();
 	}
-	exit();
+	System::exit();
 }

mod/share.php

@@ -21,6 +21,7 @@
 
 use Friendica\App;
 use Friendica\Content\Text\BBCode;
+use Friendica\Core\System;
 use Friendica\Database\DBA;
 use Friendica\DI;
 use Friendica\Model\Item;
@@ -30,7 +31,7 @@ function share_init(App $a) {
 	$post_id = ((DI::args()->getArgc() > 1) ? intval(DI::args()->getArgv()[1]) : 0);
 
 	if (!$post_id || !local_user()) {
-		exit();
+		System::exit();
 	}
 
 	$fields = ['private', 'body', 'author-name', 'author-link', 'author-avatar',
@@ -38,7 +39,7 @@ function share_init(App $a) {
 	$item = Post::selectFirst($fields, ['id' => $post_id]);
 
 	if (!DBA::isResult($item) || $item['private'] == Item::PRIVATE) {
-		exit();
+		System::exit();
 	}
 
 	if (strpos($item['body'], "[/share]") !== false) {
@@ -56,5 +57,5 @@ function share_init(App $a) {
 	}
 
 	echo $o;
-	exit();
+	System::exit();
 }

mod/tagger.php

@@ -167,6 +167,5 @@ EOT;
 	$post = Post::selectFirst(['uri-id', 'uid'], ['id' => $post_id]);
 
 	Worker::add(PRIORITY_HIGH, "Notifier", Delivery::POST, $post['uri-id'], $post['uid']);
-
-	exit();
+	System::exit();
 }

mod/wall_attach.php

@@ -67,14 +67,14 @@ function wall_attach_post(App $a) {
 			System::jsonExit(['error' => DI::l10n()->t('Permission denied.')]);
 		}
 		notice(DI::l10n()->t('Permission denied.') . EOL );
-		exit();
+		System::exit();
 	}
 
 	if (empty($_FILES['userfile'])) {
 		if ($r_json) {
 			System::jsonExit(['error' => DI::l10n()->t('Invalid request.')]);
 		}
-		exit();
+		System::exit();
 	}
 
 	$src      = $_FILES['userfile']['tmp_name'];
@@ -97,7 +97,7 @@ function wall_attach_post(App $a) {
 		} else {
 			notice($msg);
 		}
-		exit();
+		System::exit();
 	}
 
 	if ($maxfilesize && $filesize > $maxfilesize) {
@@ -108,7 +108,7 @@ function wall_attach_post(App $a) {
 		} else {
 			echo $msg . EOL;
 		}
-		exit();
+		System::exit();
 	}
 
 	$newid = Attach::storeFile($src, $page_owner_uid, $filename, '<' . $page_owner_cid . '>');
@@ -122,7 +122,7 @@ function wall_attach_post(App $a) {
 		} else {
 			echo $msg . EOL;
 		}
-		exit();
+		System::exit();
 	}
 
 	if ($r_json) {
@@ -132,7 +132,6 @@ function wall_attach_post(App $a) {
 	$lf = "\n";
 
 	echo  $lf . $lf . '[attachment]' . $newid . '[/attachment]' . $lf;
-
-	exit();
+	System::exit();
 	// NOTREACHED
 }

mod/wall_upload.php

@@ -89,14 +89,14 @@ function wall_upload_post(App $a, $desktopmode = true)
 			System::jsonExit(['error' => DI::l10n()->t('Permission denied.')]);
 		}
 		notice(DI::l10n()->t('Permission denied.'));
-		exit();
+		System::exit();
 	}
 
 	if (empty($_FILES['userfile']) && empty($_FILES['media'])) {
 		if ($r_json) {
 			System::jsonExit(['error' => DI::l10n()->t('Invalid request.')]);
 		}
-		exit();
+		System::exit();
 	}
 
 	$src = '';
@@ -148,7 +148,7 @@ function wall_upload_post(App $a, $desktopmode = true)
 			System::jsonExit(['error' => DI::l10n()->t('Invalid request.')]);
 		}
 		notice(DI::l10n()->t('Invalid request.'));
-		exit();
+		System::exit();
 	}
 
 	$filetype = Images::getMimeTypeBySource($src, $filename, $filetype);
@@ -167,7 +167,7 @@ function wall_upload_post(App $a, $desktopmode = true)
 		} else {
 			echo  $msg. EOL;
 		}
-		exit();
+		System::exit();
 	}
 
 	$Image->orient($src);
@@ -205,7 +205,7 @@ function wall_upload_post(App $a, $desktopmode = true)
 			} else {
 				echo  $msg. EOL;
 			}
-			exit();
+			System::exit();
 		}
 	}
 
@@ -229,7 +229,7 @@ function wall_upload_post(App $a, $desktopmode = true)
 		} else {
 			echo  $msg. EOL;
 		}
-		exit();
+		System::exit();
 	}
 
 	if ($width > 640 || $height > 640) {
@@ -281,6 +281,6 @@ function wall_upload_post(App $a, $desktopmode = true)
 	}
 
 	echo  "\n\n" . '[url=' . DI::baseUrl() . '/photos/' . $page_owner_nick . '/image/' . $resource_id . '][img]' . DI::baseUrl() . "/photo/{$resource_id}-{$smallest}.".$Image->getExt()."[/img][/url]\n\n";
-	exit();
+	System::exit();
 	// NOTREACHED
 }

src/App.php

@@ -576,6 +576,7 @@ class App
 		$this->profiler->set(microtime(true), 'classinit');
 
 		$moduleName = $this->args->getModuleName();
+		$page->setLogging($this->args->getCommand(), $this->args->getMethod());
 
 		try {
 			// Missing DB connection: ERROR
@@ -718,6 +719,7 @@ class App
 		} catch (HTTPException $e) {
 			(new ModuleHTTPException())->rawContent($e);
 		}
+		$page->logRuntime();
 	}
 
 	/**

src/App/Page.php

@@ -30,6 +30,7 @@ use Friendica\Core\Config\Capability\IManageConfigValues;
 use Friendica\Core\PConfig\Capability\IManagePersonalConfigValues;
 use Friendica\Core\Hook;
 use Friendica\Core\L10n;
+use Friendica\Core\Logger;
 use Friendica\Core\Renderer;
 use Friendica\Core\System;
 use Friendica\Core\Theme;
@@ -78,14 +79,31 @@ class Page implements ArrayAccess
 	 */
 	private $basePath;
 
+	private $timestamp = 0;
+	private $command   = '';
+	private $method    = '';
+
 	/**
 	 * @param string $basepath The Page basepath
 	 */
 	public function __construct(string $basepath)
 	{
+		$this->timestamp = microtime(true);
 		$this->basePath = $basepath;
 	}
 
+	public function setLogging(string $command, string $method)
+	{
+		$this->command = $command;
+		$this->method  = $method;
+	}
+
+	public function logRuntime()
+	{
+		$runtime = number_format(microtime(true) - $this->timestamp, 3);
+		Logger::debug('Runtime', ['method' => $this->method, 'command' => $this->command, 'runtime' => $runtime]);
+	}
+
 	/**
 	 * Whether a offset exists
 	 *
@@ -421,6 +439,9 @@ class Page implements ArrayAccess
 	{
 		$moduleName = $args->getModuleName();
 
+		$this->command = $moduleName;
+		$this->method  = $args->getMethod();
+
 		/* Create the page content.
 		 * Calls all hooks which are including content operations
 		 *

src/Core/System.php

@@ -295,7 +295,7 @@ class System
 		DI::apiResponse()->addContent(XML::fromArray(["result" => $result], $xml));
 		DI::page()->exit(DI::apiResponse()->generate());
 
-		exit();
+		self::exit();
 	}
 
 	/**
@@ -315,7 +315,7 @@ class System
 		DI::apiResponse()->addContent($content);
 		DI::page()->exit(DI::apiResponse()->generate());
 
-		exit();
+		self::exit();
 	}
 
 	/**
@@ -331,7 +331,8 @@ class System
 		DI::apiResponse()->setType($responce, $content_type);
 		DI::apiResponse()->addContent($content);
 		DI::page()->exit(DI::apiResponse()->generate());
-		exit();
+
+		self::exit();
 	}
 
 	public static function jsonError($httpCode, $content, $content_type = 'application/json')
@@ -359,6 +360,16 @@ class System
 		DI::apiResponse()->setType(Response::TYPE_JSON, $content_type);
 		DI::apiResponse()->addContent(json_encode($content, $options));
 		DI::page()->exit(DI::apiResponse()->generate());
+
+		self::exit();
+	}
+
+	/**
+	 * Exit the program execution.
+	 */
+	public static function exit()
+	{
+		DI::page()->logRuntime();
 		exit();
 	}
 
@@ -448,8 +459,7 @@ class System
 			case 307:
 				throw new TemporaryRedirectException();
 		}
-
-		exit();
+		self::exit();
 	}
 
 	/**
@@ -522,7 +532,7 @@ class System
 		echo str_replace("\t", "       ", $o);
 		echo "</section>";
 		echo "</body></html>\r\n";
-		exit();
+		self::exit();
 	}
 
 	/**

src/Module/Admin/PhpInfo.php

@@ -21,6 +21,7 @@
 
 namespace Friendica\Module\Admin;
 
+use Friendica\Core\System;
 use Friendica\Module\BaseAdmin;
 
 class PhpInfo extends BaseAdmin
@@ -30,6 +31,6 @@ class PhpInfo extends BaseAdmin
 		self::checkAdminAccess();
 
 		phpinfo();
-		exit();
+		System::exit();
 	}
 }

src/Module/Attach.php

@@ -23,6 +23,7 @@ namespace Friendica\Module;
 
 use Friendica\BaseModule;
 use Friendica\Core\Logger;
+use Friendica\Core\System;
 use Friendica\DI;
 use Friendica\Model\Attach as MAttach;
 
@@ -72,7 +73,7 @@ class Attach extends BaseModule
 		}
 
 		echo $data;
-		exit();
+		System::exit();
 		// NOTREACHED
 	}
 }

src/Module/Contact/Hovercard.php

@@ -24,6 +24,7 @@ namespace Friendica\Module\Contact;
 use Friendica\BaseModule;
 use Friendica\Core\Renderer;
 use Friendica\Core\Session;
+use Friendica\Core\System;
 use Friendica\Database\DBA;
 use Friendica\DI;
 use Friendica\Model\Contact;
@@ -107,6 +108,6 @@ class Hovercard extends BaseModule
 		]);
 
 		echo $o;
-		exit();
+		System::exit();
 	}
 }

src/Module/Debug/ItemBody.php

@@ -22,6 +22,7 @@
 namespace Friendica\Module\Debug;
 
 use Friendica\BaseModule;
+use Friendica\Core\System;
 use Friendica\DI;
 use Friendica\Model\Post;
 use Friendica\Network\HTTPException;
@@ -48,7 +49,7 @@ class ItemBody extends BaseModule
 		if (!empty($item)) {
 			if (DI::mode()->isAjax()) {
 				echo str_replace("\n", '<br />', $item['body']);
-				exit();
+				System::exit();
 			} else {
 				return str_replace("\n", '<br />', $item['body']);
 			}

src/Module/Group.php

@@ -360,7 +360,7 @@ class Group extends BaseModule
 		if ($change) {
 			$tpl = Renderer::getMarkupTemplate('groupeditor.tpl');
 			echo Renderer::replaceMacros($tpl, $context);
-			exit();
+			System::exit();
 		}
 
 		return Renderer::replaceMacros($tpl, $context);

src/Module/HTTPException/PageNotFound.php

@@ -22,6 +22,7 @@
 namespace Friendica\Module\HTTPException;
 
 use Friendica\BaseModule;
+use Friendica\Core\System;
 use Friendica\DI;
 use Friendica\Network\HTTPException;
 use Psr\Http\Message\ResponseInterface;
@@ -47,7 +48,7 @@ class PageNotFound extends BaseModule
 		$queryString = $this->server['QUERY_STRING'];
 		// Stupid browser tried to pre-fetch our Javascript img template. Don't log the event or return anything - just quietly exit.
 		if (!empty($queryString) && preg_match('/{[0-9]}/', $queryString) !== 0) {
-			exit();
+			System::exit();
 		}
 
 		if (!empty($queryString) && ($queryString === 'q=internal_error.html') && isset($dreamhost_error_hack)) {

src/Module/Oembed.php

@@ -23,6 +23,7 @@ namespace Friendica\Module;
 
 use Friendica\BaseModule;
 use Friendica\Content;
+use Friendica\Core\System;
 use Friendica\DI;
 use Friendica\Util\Strings;
 
@@ -43,14 +44,14 @@ class Oembed extends BaseModule
 		if (DI::args()->getArgv()[1] == 'b2h') {
 			$url = ["", trim(hex2bin($_REQUEST['url']))];
 			echo Content\OEmbed::replaceCallback($url);
-			exit();
+			System::exit();
 		}
 
 		// Unused form: /oembed/h2b?text=...
 		if (DI::args()->getArgv()[1] == 'h2b') {
 			$text = trim(hex2bin($_REQUEST['text']));
 			echo Content\OEmbed::HTML2BBCode($text);
-			exit();
+			System::exit();
 		}
 
 		// @TODO: Replace with parameter from router
@@ -68,6 +69,6 @@ class Oembed extends BaseModule
 			echo $j->html;
 			echo '</body></html>';
 		}
-		exit();
+		System::exit();
 	}
 }

src/Module/PermissionTooltip.php

@@ -22,6 +22,7 @@
 namespace Friendica\Module;
 
 use Friendica\Core\Hook;
+use Friendica\Core\System;
 use Friendica\Database\DBA;
 use Friendica\DI;
 use Friendica\Model\APContact;
@@ -164,8 +165,7 @@ class PermissionTooltip extends \Friendica\BaseModule
 		} else {
 			echo $o . $receivers;
 		}
-
-		exit();
+		System::exit();
 	}
 
 	/**

src/Module/Photo.php

@@ -32,6 +32,7 @@ use Friendica\Model\Post;
 use Friendica\Model\Profile;
 use Friendica\Core\Storage\Type\ExternalResource;
 use Friendica\Core\Storage\Type\SystemResource;
+use Friendica\Core\System;
 use Friendica\Core\Worker;
 use Friendica\Model\User;
 use Friendica\Network\HTTPClient\Client\HttpClientAccept;
@@ -224,7 +225,7 @@ class Photo extends BaseModule
 				'output' => number_format($output, 3), 'rest' => number_format($rest, 3)]);
 		}
 
-		exit();
+		System::exit();
 	}
 
 	private static function getPhotoByid(int $id, $type, $customsize)

src/Module/Proxy.php

@@ -202,6 +202,6 @@ class Proxy extends BaseModule
 		header('Expires: ' . gmdate('D, d M Y H:i:s', time() + (31536000)) . ' GMT');
 		header('Cache-Control: max-age=31536000');
 		echo $img->asString();
-		exit();
+		System::exit();
 	}
 }

src/Module/RobotsTxt.php

@@ -22,6 +22,7 @@
 namespace Friendica\Module;
 
 use Friendica\BaseModule;
+use Friendica\Core\System;
 
 /**
  * Return the default robots.txt
@@ -44,6 +45,6 @@ class RobotsTxt extends BaseModule
 		foreach ($allDisalloweds as $disallowed) {
 			echo 'Disallow: ' . $disallowed . PHP_EOL;
 		}
-		exit();
+		System::exit();
 	}
 }

src/Module/Settings/UserExport.php

@@ -23,6 +23,7 @@ namespace Friendica\Module\Settings;
 
 use Friendica\Core\Hook;
 use Friendica\Core\Renderer;
+use Friendica\Core\System;
 use Friendica\Database\DBA;
 use Friendica\Database\DBStructure;
 use Friendica\DI;
@@ -112,8 +113,7 @@ class UserExport extends BaseSettings
 					self::exportContactsAsCSV(local_user());
 					break;
 			}
-
-			exit();
+			System::exit();
 		}
 	}
 

src/Module/Theme.php

@@ -22,7 +22,7 @@
 namespace Friendica\Module;
 
 use Friendica\BaseModule;
-use Friendica\DI;
+use Friendica\Core\System;
 use Friendica\Util\Strings;
 
 /**
@@ -45,7 +45,6 @@ class Theme extends BaseModule
 		if (file_exists("view/theme/$theme/style.php")) {
 			require_once "view/theme/$theme/style.php";
 		}
-
-		exit();
+		System::exit();
 	}
 }

src/Module/ThemeDetails.php

@@ -48,6 +48,6 @@ class ThemeDetails extends BaseModule
 				'credits' => $credits,
 			]);
 		}
-		exit();
+		System::exit();
 	}
 }

src/Module/Update/Network.php

@@ -31,7 +31,7 @@ class Network extends NetworkModule
 	protected function rawContent(array $request = [])
 	{
 		if (!isset($_GET['p']) || !isset($_GET['item'])) {
-			exit();
+			System::exit();
 		}
 
 		$this->parseRequest($_GET);

src/Util/JsonLD.php

@@ -24,6 +24,7 @@ namespace Friendica\Util;
 use Friendica\Core\Cache\Enum\Duration;
 use Friendica\Core\Logger;
 use Exception;
+use Friendica\Core\System;
 use Friendica\DI;
 
 /**
@@ -69,7 +70,7 @@ class JsonLD
 
 		if ($recursion > 5) {
 			Logger::error('jsonld bomb detected at: ' . $url);
-			exit();
+			System::exit();
 		}
 
 		$result = DI::cache()->get('documentLoader:' . $url);