From 4016a576d55d2e9b4b3acbe515a73b8c025ef215 Mon Sep 17 00:00:00 2001 From: Michael Date: Tue, 17 May 2022 20:47:23 +0000 Subject: [PATCH] Log the execution time --- mod/fbrowser.php | 2 ++ mod/photos.php | 2 ++ mod/pubsub.php | 1 + mod/pubsubhubbub.php | 1 + mod/share.php | 3 +++ mod/tagger.php | 2 +- mod/wall_attach.php | 7 ++++++- mod/wall_upload.php | 7 +++++++ src/App.php | 2 ++ src/App/Page.php | 22 ++++++++++++++++++++++ src/Core/System.php | 3 ++- src/Module/Admin/PhpInfo.php | 1 + src/Module/Attach.php | 1 + src/Module/Contact/Hovercard.php | 1 + src/Module/Debug/ItemBody.php | 1 + src/Module/Group.php | 1 + src/Module/HTTPException/PageNotFound.php | 1 + src/Module/Oembed.php | 3 +++ src/Module/PermissionTooltip.php | 2 +- src/Module/Photo.php | 1 + src/Module/Proxy.php | 1 + src/Module/RobotsTxt.php | 1 + src/Module/Settings/UserExport.php | 2 +- src/Module/Theme.php | 2 +- src/Module/ThemeDetails.php | 1 + src/Module/Update/Network.php | 1 + src/Util/JsonLD.php | 1 + 27 files changed, 67 insertions(+), 6 deletions(-) diff --git a/mod/fbrowser.php b/mod/fbrowser.php index 1646b19dff..4e887c7eb0 100644 --- a/mod/fbrowser.php +++ b/mod/fbrowser.php @@ -39,10 +39,12 @@ use Friendica\Util\Strings; function fbrowser_content(App $a) { if (!local_user()) { + DI::page()->logRuntime(); exit(); } if (DI::args()->getArgc() == 1) { + DI::page()->logRuntime(); exit(); } diff --git a/mod/photos.php b/mod/photos.php index ce6d11340e..fa8a434c44 100644 --- a/mod/photos.php +++ b/mod/photos.php @@ -158,6 +158,7 @@ function photos_post(App $a) if (!$can_post) { notice(DI::l10n()->t('Permission denied.')); + DI::page()->logRuntime(); exit(); } @@ -166,6 +167,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); + DI::page()->logRuntime(); exit(); } diff --git a/mod/pubsub.php b/mod/pubsub.php index e07b15583c..630b68f504 100644 --- a/mod/pubsub.php +++ b/mod/pubsub.php @@ -38,6 +38,7 @@ function hub_return($valid, $body) } else { throw new \Friendica\Network\HTTPException\NotFoundException(); } + DI::page()->logRuntime(); exit(); } diff --git a/mod/pubsubhubbub.php b/mod/pubsubhubbub.php index 361cb0a597..5300f783d4 100644 --- a/mod/pubsubhubbub.php +++ b/mod/pubsubhubbub.php @@ -142,5 +142,6 @@ function pubsubhubbub_init(App $a) { throw new \Friendica\Network\HTTPException\AcceptedException(); } + DI::page()->logRuntime(); exit(); } diff --git a/mod/share.php b/mod/share.php index b18655aef8..dde3864bc4 100644 --- a/mod/share.php +++ b/mod/share.php @@ -30,6 +30,7 @@ function share_init(App $a) { $post_id = ((DI::args()->getArgc() > 1) ? intval(DI::args()->getArgv()[1]) : 0); if (!$post_id || !local_user()) { + DI::page()->logRuntime(); exit(); } @@ -38,6 +39,7 @@ function share_init(App $a) { $item = Post::selectFirst($fields, ['id' => $post_id]); if (!DBA::isResult($item) || $item['private'] == Item::PRIVATE) { + DI::page()->logRuntime(); exit(); } @@ -56,5 +58,6 @@ function share_init(App $a) { } echo $o; + DI::page()->logRuntime(); exit(); } diff --git a/mod/tagger.php b/mod/tagger.php index 310e3c6140..4c0af4a532 100644 --- a/mod/tagger.php +++ b/mod/tagger.php @@ -167,6 +167,6 @@ EOT; $post = Post::selectFirst(['uri-id', 'uid'], ['id' => $post_id]); Worker::add(PRIORITY_HIGH, "Notifier", Delivery::POST, $post['uri-id'], $post['uid']); - + DI::page()->logRuntime(); exit(); } diff --git a/mod/wall_attach.php b/mod/wall_attach.php index 607d0fe7a3..6dfa40b095 100644 --- a/mod/wall_attach.php +++ b/mod/wall_attach.php @@ -67,6 +67,7 @@ function wall_attach_post(App $a) { System::jsonExit(['error' => DI::l10n()->t('Permission denied.')]); } notice(DI::l10n()->t('Permission denied.') . EOL ); + DI::page()->logRuntime(); exit(); } @@ -74,6 +75,7 @@ function wall_attach_post(App $a) { if ($r_json) { System::jsonExit(['error' => DI::l10n()->t('Invalid request.')]); } + DI::page()->logRuntime(); exit(); } @@ -97,6 +99,7 @@ function wall_attach_post(App $a) { } else { notice($msg); } + DI::page()->logRuntime(); exit(); } @@ -108,6 +111,7 @@ function wall_attach_post(App $a) { } else { echo $msg . EOL; } + DI::page()->logRuntime(); exit(); } @@ -122,6 +126,7 @@ function wall_attach_post(App $a) { } else { echo $msg . EOL; } + DI::page()->logRuntime(); exit(); } @@ -132,7 +137,7 @@ function wall_attach_post(App $a) { $lf = "\n"; echo $lf . $lf . '[attachment]' . $newid . '[/attachment]' . $lf; - + DI::page()->logRuntime(); exit(); // NOTREACHED } diff --git a/mod/wall_upload.php b/mod/wall_upload.php index 79f1dcc41f..8b8b1df9a4 100644 --- a/mod/wall_upload.php +++ b/mod/wall_upload.php @@ -89,6 +89,7 @@ function wall_upload_post(App $a, $desktopmode = true) System::jsonExit(['error' => DI::l10n()->t('Permission denied.')]); } notice(DI::l10n()->t('Permission denied.')); + DI::page()->logRuntime(); exit(); } @@ -96,6 +97,7 @@ function wall_upload_post(App $a, $desktopmode = true) if ($r_json) { System::jsonExit(['error' => DI::l10n()->t('Invalid request.')]); } + DI::page()->logRuntime(); exit(); } @@ -148,6 +150,7 @@ function wall_upload_post(App $a, $desktopmode = true) System::jsonExit(['error' => DI::l10n()->t('Invalid request.')]); } notice(DI::l10n()->t('Invalid request.')); + DI::page()->logRuntime(); exit(); } @@ -167,6 +170,7 @@ function wall_upload_post(App $a, $desktopmode = true) } else { echo $msg. EOL; } + DI::page()->logRuntime(); exit(); } @@ -205,6 +209,7 @@ function wall_upload_post(App $a, $desktopmode = true) } else { echo $msg. EOL; } + DI::page()->logRuntime(); exit(); } } @@ -229,6 +234,7 @@ function wall_upload_post(App $a, $desktopmode = true) } else { echo $msg. EOL; } + DI::page()->logRuntime(); exit(); } @@ -281,6 +287,7 @@ 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"; + DI::page()->logRuntime(); exit(); // NOTREACHED } diff --git a/src/App.php b/src/App.php index f7c929820d..bf5c309ed3 100644 --- a/src/App.php +++ b/src/App.php @@ -576,6 +576,7 @@ class App $this->profiler->set(microtime(true), 'classinit'); $moduleName = $this->args->getModuleName(); + $page->setLogging($moduleName, $this->args->getMethod()); try { // Missing DB connection: ERROR @@ -712,6 +713,7 @@ class App $this->profiler->set(microtime(true) - $timestamp, 'content'); if ($response->getHeaderLine(ICanCreateResponses::X_HEADER) === ICanCreateResponses::TYPE_HTML) { $page->run($this, $this->baseURL, $this->args, $this->mode, $response, $this->l10n, $this->profiler, $this->config, $pconfig); + $page->logRuntime(); } else { $page->exit($response); } diff --git a/src/App/Page.php b/src/App/Page.php index 14f0101ef0..8986d4aa91 100644 --- a/src/App/Page.php +++ b/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 $moduleName = ''; + private $method = ''; + /** * @param string $basepath The Page basepath */ public function __construct(string $basepath) { + $this->timestamp = microtime(true); $this->basePath = $basepath; } + public function setLogging(string $moduleName, string $method) + { + $this->moduleName = $moduleName; + $this->method = $method; + } + + public function logRuntime() + { + $runtime = number_format(microtime(true) - $this->timestamp, 3); + Logger::debug('Runtime', ['method' => $this->method, 'module' => $this->moduleName, 'runtime' => $runtime]); + } + /** * Whether a offset exists * @@ -401,6 +419,7 @@ class Page implements ArrayAccess } echo $response->getBody(); + $this->logRuntime(); } /** @@ -421,6 +440,9 @@ class Page implements ArrayAccess { $moduleName = $args->getModuleName(); + $this->moduleName = $moduleName; + $this->method = $args->getMethod(); + /* Create the page content. * Calls all hooks which are including content operations * diff --git a/src/Core/System.php b/src/Core/System.php index 66b6b25a50..7b0a887cdf 100644 --- a/src/Core/System.php +++ b/src/Core/System.php @@ -448,7 +448,7 @@ class System case 307: throw new TemporaryRedirectException(); } - + DI::page()->logRuntime(); exit(); } @@ -522,6 +522,7 @@ class System echo str_replace("\t", " ", $o); echo ""; echo "\r\n"; + DI::page()->logRuntime(); exit(); } diff --git a/src/Module/Admin/PhpInfo.php b/src/Module/Admin/PhpInfo.php index 0177424f3d..732753b593 100644 --- a/src/Module/Admin/PhpInfo.php +++ b/src/Module/Admin/PhpInfo.php @@ -30,6 +30,7 @@ class PhpInfo extends BaseAdmin self::checkAdminAccess(); phpinfo(); + DI::page()->logRuntime(); exit(); } } diff --git a/src/Module/Attach.php b/src/Module/Attach.php index 60d1015b0a..fc7ba74d59 100644 --- a/src/Module/Attach.php +++ b/src/Module/Attach.php @@ -72,6 +72,7 @@ class Attach extends BaseModule } echo $data; + DI::page()->logRuntime(); exit(); // NOTREACHED } diff --git a/src/Module/Contact/Hovercard.php b/src/Module/Contact/Hovercard.php index cd03e2533a..2bf6f63ed2 100644 --- a/src/Module/Contact/Hovercard.php +++ b/src/Module/Contact/Hovercard.php @@ -107,6 +107,7 @@ class Hovercard extends BaseModule ]); echo $o; + DI::page()->logRuntime(); exit(); } } diff --git a/src/Module/Debug/ItemBody.php b/src/Module/Debug/ItemBody.php index 55abc894ed..e066e7656a 100644 --- a/src/Module/Debug/ItemBody.php +++ b/src/Module/Debug/ItemBody.php @@ -48,6 +48,7 @@ class ItemBody extends BaseModule if (!empty($item)) { if (DI::mode()->isAjax()) { echo str_replace("\n", '
', $item['body']); + DI::page()->logRuntime(); exit(); } else { return str_replace("\n", '
', $item['body']); diff --git a/src/Module/Group.php b/src/Module/Group.php index 3cd8166f1f..4825debd02 100644 --- a/src/Module/Group.php +++ b/src/Module/Group.php @@ -360,6 +360,7 @@ class Group extends BaseModule if ($change) { $tpl = Renderer::getMarkupTemplate('groupeditor.tpl'); echo Renderer::replaceMacros($tpl, $context); + DI::page()->logRuntime(); exit(); } diff --git a/src/Module/HTTPException/PageNotFound.php b/src/Module/HTTPException/PageNotFound.php index a73757d828..ba34df8544 100644 --- a/src/Module/HTTPException/PageNotFound.php +++ b/src/Module/HTTPException/PageNotFound.php @@ -47,6 +47,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) { + DI::page()->logRuntime(); exit(); } diff --git a/src/Module/Oembed.php b/src/Module/Oembed.php index 81c858cba3..49b4792042 100644 --- a/src/Module/Oembed.php +++ b/src/Module/Oembed.php @@ -43,6 +43,7 @@ class Oembed extends BaseModule if (DI::args()->getArgv()[1] == 'b2h') { $url = ["", trim(hex2bin($_REQUEST['url']))]; echo Content\OEmbed::replaceCallback($url); + DI::page()->logRuntime(); exit(); } @@ -50,6 +51,7 @@ class Oembed extends BaseModule if (DI::args()->getArgv()[1] == 'h2b') { $text = trim(hex2bin($_REQUEST['text'])); echo Content\OEmbed::HTML2BBCode($text); + DI::page()->logRuntime(); exit(); } @@ -68,6 +70,7 @@ class Oembed extends BaseModule echo $j->html; echo ''; } + DI::page()->logRuntime(); exit(); } } diff --git a/src/Module/PermissionTooltip.php b/src/Module/PermissionTooltip.php index ff0bae1bc4..edc839a38e 100644 --- a/src/Module/PermissionTooltip.php +++ b/src/Module/PermissionTooltip.php @@ -164,7 +164,7 @@ class PermissionTooltip extends \Friendica\BaseModule } else { echo $o . $receivers; } - + DI::page()->logRuntime(); exit(); } diff --git a/src/Module/Photo.php b/src/Module/Photo.php index 9e56301b44..d050188aac 100644 --- a/src/Module/Photo.php +++ b/src/Module/Photo.php @@ -224,6 +224,7 @@ class Photo extends BaseModule 'output' => number_format($output, 3), 'rest' => number_format($rest, 3)]); } + DI::page()->logRuntime(); exit(); } diff --git a/src/Module/Proxy.php b/src/Module/Proxy.php index 3ef3117d69..0af49762e9 100644 --- a/src/Module/Proxy.php +++ b/src/Module/Proxy.php @@ -202,6 +202,7 @@ 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(); + DI::page()->logRuntime(); exit(); } } diff --git a/src/Module/RobotsTxt.php b/src/Module/RobotsTxt.php index 1fcf1269ed..e4b1af7abe 100644 --- a/src/Module/RobotsTxt.php +++ b/src/Module/RobotsTxt.php @@ -44,6 +44,7 @@ class RobotsTxt extends BaseModule foreach ($allDisalloweds as $disallowed) { echo 'Disallow: ' . $disallowed . PHP_EOL; } + DI::page()->logRuntime(); exit(); } } diff --git a/src/Module/Settings/UserExport.php b/src/Module/Settings/UserExport.php index 1d47df4fd3..6af321a0b7 100644 --- a/src/Module/Settings/UserExport.php +++ b/src/Module/Settings/UserExport.php @@ -112,7 +112,7 @@ class UserExport extends BaseSettings self::exportContactsAsCSV(local_user()); break; } - + DI::page()->logRuntime(); exit(); } } diff --git a/src/Module/Theme.php b/src/Module/Theme.php index 66c9d06f07..8d14d82dad 100644 --- a/src/Module/Theme.php +++ b/src/Module/Theme.php @@ -45,7 +45,7 @@ class Theme extends BaseModule if (file_exists("view/theme/$theme/style.php")) { require_once "view/theme/$theme/style.php"; } - + DI::page()->logRuntime(); exit(); } } diff --git a/src/Module/ThemeDetails.php b/src/Module/ThemeDetails.php index 6398a00c99..1bd45913a6 100644 --- a/src/Module/ThemeDetails.php +++ b/src/Module/ThemeDetails.php @@ -48,6 +48,7 @@ class ThemeDetails extends BaseModule 'credits' => $credits, ]); } + DI::page()->logRuntime(); exit(); } } diff --git a/src/Module/Update/Network.php b/src/Module/Update/Network.php index 330cba2d3e..2b71d23c4e 100644 --- a/src/Module/Update/Network.php +++ b/src/Module/Update/Network.php @@ -31,6 +31,7 @@ class Network extends NetworkModule protected function rawContent(array $request = []) { if (!isset($_GET['p']) || !isset($_GET['item'])) { + DI::page()->logRuntime(); exit(); } diff --git a/src/Util/JsonLD.php b/src/Util/JsonLD.php index cf1e058a14..c2271565c2 100644 --- a/src/Util/JsonLD.php +++ b/src/Util/JsonLD.php @@ -69,6 +69,7 @@ class JsonLD if ($recursion > 5) { Logger::error('jsonld bomb detected at: ' . $url); + DI::page()->logRuntime(); exit(); }