From 2ef34ef02b95e21539d210b56d7f914909a5703a Mon Sep 17 00:00:00 2001 From: Dominik Hebeler <dominik@suma-ev.de> Date: Wed, 25 May 2022 10:00:26 +0200 Subject: [PATCH] QueryTimings are exported to prometheus --- .../app/Http/Controllers/MetaGerSearch.php | 74 ++++++++----------- .../Http/Middleware/BrowserVerification.php | 56 ++++++++------ .../app/Http/Middleware/HumanVerification.php | 9 +++ metager/app/Http/Middleware/RemoveKey.php | 1 + .../app/Http/Middleware/UserAgentMaster.php | 3 + metager/app/MetaGer.php | 65 +++------------- metager/app/Models/Adgoal.php | 3 - metager/app/Models/Searchengine.php | 16 +--- metager/app/Providers/MetaGerProvider.php | 10 +++ metager/app/QueryTimer.php | 29 +++++++- 10 files changed, 126 insertions(+), 140 deletions(-) diff --git a/metager/app/Http/Controllers/MetaGerSearch.php b/metager/app/Http/Controllers/MetaGerSearch.php index 0d2b744e3..2f3de5e43 100644 --- a/metager/app/Http/Controllers/MetaGerSearch.php +++ b/metager/app/Http/Controllers/MetaGerSearch.php @@ -11,11 +11,13 @@ use Illuminate\Support\Facades\Log; use Prometheus\CollectorRegistry; use Illuminate\Support\Facades\View; use Illuminate\Support\Facades\App; +use App\QueryTimer; class MetaGerSearch extends Controller { public function search(Request $request, MetaGer $metager, $timing = false) { + $query_timer = \app()->make(QueryTimer::class); $locale = LaravelLocalization::getCurrentLocale(); $preferredLanguage = array($request->getPreferredLanguage()); if (!empty($preferredLanguage) && !empty($locale)) { @@ -25,11 +27,6 @@ class MetaGerSearch extends Controller if ($request->filled("chrome-plugin")) { return redirect(LaravelLocalization::getLocalizedURL(LaravelLocalization::getCurrentLocale(), "/plugin")); } - $timings = null; - if ($timing) { - $timings = ['starttime' => microtime(true)]; - } - $time = microtime(true); $focus = $request->input("focus", "web"); @@ -45,16 +42,14 @@ class MetaGerSearch extends Controller } # Mit gelieferte Formulardaten parsen und abspeichern: + $query_timer->observeStart("Search_ParseFormData"); $metager->parseFormData($request); - if (!empty($timings)) { - $timings["parseFormData"] = microtime(true) - $time; - } + $query_timer->observeEnd("Search_ParseFormData"); # Nach Spezialsuchen überprüfen: + $query_timer->observeStart("Search_CheckSpecialSearches"); $metager->checkSpecialSearches($request); - if (!empty($timings)) { - $timings["checkSpecialSearches"] = microtime(true) - $time; - } + $query_timer->observeEnd("Search_CheckSpecialSearches"); # Search query can be empty after parsing the formdata # we will cancel the search in that case and show an error to the user @@ -62,47 +57,50 @@ class MetaGerSearch extends Controller return $metager->createView(); } + $query_timer->observeStart("Search_CreateQuicktips"); $quicktips = $metager->createQuicktips(); - if (!empty($timings)) { - $timings["createQuicktips"] = microtime(true) - $time; - } + $query_timer->observeEnd("Search_CreateQuicktips"); # Suche für alle zu verwendenden Suchmaschinen als Job erstellen, # auf Ergebnisse warten und die Ergebnisse laden - $metager->createSearchEngines($request, $timings); + $query_timer->observeStart("Search_CreateSearchEngines"); + $metager->createSearchEngines($request); + $query_timer->observeEnd("Search_CreateSearchEngines"); - $metager->startSearch($timings); + $query_timer->observeStart("Search_StartSearch"); + $metager->startSearch(); + $query_timer->observeEnd("Search_StartSearch"); # Versuchen die Ergebnisse der Quicktips zu laden if ($quicktips !== null) { + $query_timer->observeStart("Search_LoadQuicktips"); $quicktipResults = $quicktips->loadResults(); - if (!empty($timings)) { - $timings["Loaded Quicktip Results"] = microtime(true) - $time; - } + $query_timer->observeEnd("Search_LoadQuicktips"); } else { $quicktipResults = []; } + $query_timer->observeStart("Search_WaitForMainResults"); $metager->waitForMainResults(); - if (!empty($timings)) { - $timings["waitForMainResults"] = microtime(true) - $time; - } + $query_timer->observeEnd("Search_WaitForMainResults"); + $query_timer->observeStart("Search_RetrieveResults"); $metager->retrieveResults(); - if (!empty($timings)) { - $timings["retrieveResults"] = microtime(true) - $time; - } + $query_timer->observeEnd("Search_RetrieveResults"); # Alle Ergebnisse vor der Zusammenführung ranken: + $query_timer->observeStart("Search_RankAll"); $metager->rankAll(); - if (!empty($timings)) { - $timings["rankAll"] = microtime(true) - $time; - } + $query_timer->observeEnd("Search_RankAll"); # Ergebnisse der Suchmaschinen kombinieren: - $metager->prepareResults($timings); + $query_timer->observeStart("Search_PrepareResults"); + $metager->prepareResults(); + $query_timer->observeEnd("Search_PrepareResults"); $admitad = []; $adgoal = []; + + $query_timer->observeStart("Search_Affiliates"); if (!$metager->isApiAuthorized() && !$metager->isDummy()) { $newAdmitad = new \App\Models\Admitad($metager); if (!empty($newAdmitad->hash)) { @@ -121,14 +119,15 @@ class MetaGerSearch extends Controller if (!$metager->isApiAuthorized() && !$metager->isDummy()) { $metager->addDonationAdvertisement(); } + $query_timer->observeEnd("Search_Affiliates"); - $finished = true; foreach ($metager->getEngines() as $engine) { if ($engine->loaded) { $engine->setNew(false); $engine->markNew(); } } + $query_timer->observeStart("Search_CacheFiller"); try { Cache::put("loader_" . $metager->getSearchUid(), [ "metager" => [ @@ -141,21 +140,11 @@ class MetaGerSearch extends Controller } catch (\Exception $e) { Log::error($e->getMessage()); } - if (!empty($timings)) { - $timings["Filled resultloader Cache"] = microtime(true) - $time; - } + $query_timer->observeEnd("Search_CacheFiller"); # Die Ausgabe erstellen: $resultpage = $metager->createView($quicktipResults); - if (!empty($timings)) { - $timings["createView"] = microtime(true) - $time; - } - - if ($timings) { - dd($timings); - } - $registry = CollectorRegistry::getDefault(); $counter = $registry->getOrRegisterCounter('metager', 'result_counter', 'counts total number of returned results', []); $counter->incBy(sizeof($metager->getResults())); @@ -169,8 +158,7 @@ class MetaGerSearch extends Controller echo ($responsePart); flush(); } - $requestTime = microtime(true) - $time; - \App\PrometheusExporter::Duration($requestTime, "request_time"); + $query_timer->observeTotal(); } public function searchTimings(Request $request, MetaGer $metager) diff --git a/metager/app/Http/Middleware/BrowserVerification.php b/metager/app/Http/Middleware/BrowserVerification.php index 470f82421..bef795954 100644 --- a/metager/app/Http/Middleware/BrowserVerification.php +++ b/metager/app/Http/Middleware/BrowserVerification.php @@ -6,6 +6,7 @@ use Closure; use Illuminate\Support\Facades\Redis; use Jenssegers\Agent\Agent; use Illuminate\Http\Request; +use App\QueryTimer; use Cache; class BrowserVerification @@ -19,23 +20,26 @@ class BrowserVerification */ public function handle($request, Closure $next, $route = "resultpage") { - + \app()->make(QueryTimer::class)->observeStart(self::class); $bvEnabled = config("metager.metager.browserverification_enabled"); if (empty($bvEnabled) || !$bvEnabled) { + \app()->make(QueryTimer::class)->observeEnd(self::class); return $next($request); } else { $whitelist = config("metager.metager.browserverification_whitelist"); $agent = new Agent(); foreach ($whitelist as $browser) { if ($agent->match($browser)) { + \app()->make(QueryTimer::class)->observeEnd(self::class); return $next($request); } } } - if(($request->input("out", "") === "api" || $request->input("out", "") === "atom10") && app('App\Models\Key')->getStatus()) { + if (($request->input("out", "") === "api" || $request->input("out", "") === "atom10") && app('App\Models\Key')->getStatus()) { header('Content-type: application/xml; charset=utf-8'); - } elseif(($request->input("out", "") === "api" || $request->input("out", "") === "atom10") && !app('App\Models\Key')->getStatus()) { + } elseif (($request->input("out", "") === "api" || $request->input("out", "") === "atom10") && !app('App\Models\Key')->getStatus()) { + \app()->make(QueryTimer::class)->observeEnd(self::class); abort(403); } else { header('Content-type: text/html; charset=utf-8'); @@ -44,6 +48,7 @@ class BrowserVerification //use parameter for middleware to skip this when using associator if (($request->filled("loadMore") && Cache::has($request->input("loadMore"))) || app('App\Models\Key')->getStatus()) { + \app()->make(QueryTimer::class)->observeEnd(self::class); return $next($request); } @@ -56,29 +61,33 @@ class BrowserVerification if (!empty($mgv)) { // Verify that key is a md5 checksum if (!preg_match("/^[a-f0-9]{32}$/", $mgv)) { + \app()->make(QueryTimer::class)->observeEnd(self::class); abort(404); } - $result = Redis::connection(config('cache.stores.redis.connection'))->blpop($mgv, 5); + $result = Redis::connection(config('cache.stores.redis.connection'))->blpop($mgv, 5); if ($result !== null) { $request->request->add(["headerPrinted" => false, "jskey" => $mgv]); + \app()->make(QueryTimer::class)->observeEnd(self::class); return $next($request); } else { # We are serving that request but log it for fail2ban self::logBrowserverification($request); + \app()->make(QueryTimer::class)->observeEnd(self::class); return $next($request); } } $key = md5($request->ip() . microtime(true)); - echo(view('layouts.resultpage.verificationHeader')->with('key', $key)->render()); + echo (view('layouts.resultpage.verificationHeader')->with('key', $key)->render()); flush(); $answer = Redis::connection(config('cache.stores.redis.connection'))->blpop($key, 2); if ($answer !== null) { - echo(view('layouts.resultpage.resources')->render()); + echo (view('layouts.resultpage.resources')->render()); flush(); $request->request->add(["headerPrinted" => true, "jskey" => $key]); + \app()->make(QueryTimer::class)->observeEnd(self::class); return $next($request); } @@ -86,30 +95,33 @@ class BrowserVerification $params["mgv"] = $key; $url = route($route, $params); - echo(view('layouts.resultpage.unverifiedResultPage') - ->with('url', $url) - ->render()); + echo (view('layouts.resultpage.unverifiedResultPage') + ->with('url', $url) + ->render()); + \app()->make(QueryTimer::class)->observeEnd(self::class); + return $next($request); } - public static function logBrowserverification(Request $request) { + public static function logBrowserverification(Request $request) + { $fail2banEnabled = config("metager.metager.fail2ban.enabled"); - if(empty($fail2banEnabled) || !$fail2banEnabled || !config("metager.metager.fail2ban.url") || !config("metager.metager.fail2ban.user") || !config("metager.metager.fail2ban.password")){ + if (empty($fail2banEnabled) || !$fail2banEnabled || !config("metager.metager.fail2ban.url") || !config("metager.metager.fail2ban.user") || !config("metager.metager.fail2ban.password")) { return; } // Submit fetch job to worker $mission = [ - "resulthash" => "captcha", - "url" => config("metager.metager.fail2ban.url") . "/browserverification/", - "useragent" => "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:81.0) Gecko/20100101 Firefox/81.0", - "username" => config("metager.metager.fail2ban.user"), - "password" => config("metager.metager.fail2ban.password"), - "headers" => [ - "ip" => $request->ip() - ], - "cacheDuration" => 0, - "name" => "Captcha", - ]; + "resulthash" => "captcha", + "url" => config("metager.metager.fail2ban.url") . "/browserverification/", + "useragent" => "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:81.0) Gecko/20100101 Firefox/81.0", + "username" => config("metager.metager.fail2ban.user"), + "password" => config("metager.metager.fail2ban.password"), + "headers" => [ + "ip" => $request->ip() + ], + "cacheDuration" => 0, + "name" => "Captcha", + ]; $mission = json_encode($mission); Redis::rpush(\App\MetaGer::FETCHQUEUE_KEY, $mission); } diff --git a/metager/app/Http/Middleware/HumanVerification.php b/metager/app/Http/Middleware/HumanVerification.php index cc8fdf7d7..ec99afec8 100644 --- a/metager/app/Http/Middleware/HumanVerification.php +++ b/metager/app/Http/Middleware/HumanVerification.php @@ -7,6 +7,7 @@ use Closure; use Cookie; use Log; use URL; +use App\QueryTimer; class HumanVerification { @@ -19,7 +20,9 @@ class HumanVerification */ public function handle($request, Closure $next) { + \app()->make(QueryTimer::class)->observeStart(self::class); if ($request->filled("loadMore") && Cache::has($request->input("loadMore"))) { + \app()->make(QueryTimer::class)->observeEnd(self::class); return $next($request); } @@ -33,13 +36,16 @@ class HumanVerification if (!empty($value) && intval($value) > 0) { Cache::decrement($token); + \app()->make(QueryTimer::class)->observeEnd(self::class); return $next($request); } else { // Token is not valid. Remove it Cache::forget($token); + \app()->make(QueryTimer::class)->observeEnd(self::class); return redirect()->to(url()->current() . '?' . http_build_query($request->except(["token", "headerPrinted", "jskey"]))); } } else { + \app()->make(QueryTimer::class)->observeEnd(self::class); return redirect()->to(url()->current() . '?' . http_build_query($request->except(["token", "headerPrinted", "jskey"]))); } } @@ -73,6 +79,7 @@ class HumanVerification //use parameter for middleware to skip this when using associator if (!config("metager.metager.botprotection.enabled") || app('App\Models\Key')->getStatus()) { $update = false; + \app()->make(QueryTimer::class)->observeEnd(self::class); return $next($request); } @@ -128,6 +135,7 @@ class HumanVerification # If the user is locked we will force a Captcha validation if ($user["locked"]) { \App\Http\Controllers\HumanVerification::logCaptcha($request); + \app()->make(QueryTimer::class)->observeEnd(self::class); return redirect()->route('captcha', ["id" => $id, "uid" => $uid, "url" => url()->full()]); } @@ -164,6 +172,7 @@ class HumanVerification } $request->request->add(['verification_id' => $user["uid"], 'verification_count' => $user["unusedResultPages"]]); + \app()->make(QueryTimer::class)->observeEnd(self::class); return $next($request); } diff --git a/metager/app/Http/Middleware/RemoveKey.php b/metager/app/Http/Middleware/RemoveKey.php index 1efb72e40..5aae84df7 100644 --- a/metager/app/Http/Middleware/RemoveKey.php +++ b/metager/app/Http/Middleware/RemoveKey.php @@ -22,6 +22,7 @@ class RemoveKey if (Cookie::has("key") && app('App\Models\Key')->getStatus() === null) { return redirect(route("removeCookie", ["ir" => url()->full()])); } + \app()->make(QueryTimer::class)->observeEnd(self::class); return $next($request); } } diff --git a/metager/app/Http/Middleware/UserAgentMaster.php b/metager/app/Http/Middleware/UserAgentMaster.php index f19fdcd3a..6be1c4a7b 100644 --- a/metager/app/Http/Middleware/UserAgentMaster.php +++ b/metager/app/Http/Middleware/UserAgentMaster.php @@ -4,6 +4,7 @@ namespace App\Http\Middleware; use Closure; use Illuminate\Support\Facades\Redis; +use App\QueryTimer; use Jenssegers\Agent\Agent; class UserAgentMaster @@ -21,6 +22,7 @@ class UserAgentMaster */ public function handle($request, Closure $next) { + \app()->make(QueryTimer::class)->observeStart(self::class); /** * Categorize the User-Agents by * 1. Platform (i.e. Ubuntu) @@ -65,6 +67,7 @@ class UserAgentMaster // Replace the User-Agent $_SERVER['HTTP_USER_AGENT'] = $newAgent; + \app()->make(QueryTimer::class)->observeEnd(self::class); return $next($request); } } diff --git a/metager/app/MetaGer.php b/metager/app/MetaGer.php index e33228ea0..c6f3c9d13 100644 --- a/metager/app/MetaGer.php +++ b/metager/app/MetaGer.php @@ -2,6 +2,7 @@ namespace App; +use App\Models\Searchengine; use Illuminate\Support\Facades\App; use Illuminate\Support\Facades\Cache; use Carbon\Carbon; @@ -254,14 +255,12 @@ class MetaGer } } - public function prepareResults(&$timings = null) + public function prepareResults() { $engines = $this->engines; // combine $this->combineResults($engines); - if (!empty($timings)) { - $timings["prepareResults"]["combined results"] = microtime(true) - $timings["starttime"]; - } + // misc (WiP) if ($this->fokus == "nachrichten") { $this->results = array_filter($this->results, function ($v, $k) { @@ -281,9 +280,7 @@ class MetaGer return ($a->getRank() < $b->getRank()) ? 1 : -1; }); } - if (!empty($timings)) { - $timings["prepareResults"]["sorted results"] = microtime(true) - $timings["starttime"]; - } + # Validate Results $newResults = []; foreach ($this->results as $result) { @@ -292,14 +289,9 @@ class MetaGer } } $this->results = $newResults; - if (!empty($timings)) { - $timings["prepareResults"]["validated results"] = microtime(true) - $timings["starttime"]; - } $this->duplicationCheck(); - if (!empty($timings)) { - $timings["prepareResults"]["duplications checked"] = microtime(true) - $timings["starttime"]; - } + # Validate Advertisements $newResults = []; foreach ($this->ads as $ad) { @@ -313,9 +305,7 @@ class MetaGer } $this->ads = $newResults; - if (!empty($timings)) { - $timings["prepareResults"]["validated ads"] = microtime(true) - $timings["starttime"]; - } + #Adgoal Implementation if (empty($this->adgoalLoaded)) { $this->adgoalLoaded = false; @@ -331,9 +321,6 @@ class MetaGer # Human Verification $this->humanVerification($this->results); $this->humanVerification($this->ads); - if (!empty($timings)) { - $timings["prepareResults"]["human verification"] = microtime(true) - $timings["starttime"]; - } $counter = 0; $firstRank = 0; @@ -354,9 +341,6 @@ class MetaGer 'engines' => $this->next, ]; Cache::put($this->getSearchUid(), serialize($this->next), 60 * 60); - if (!empty($timings)) { - $timings["prepareResults"]["filled cache"] = microtime(true) - $timings["starttime"]; - } } else { $this->next = []; } @@ -512,12 +496,8 @@ class MetaGer * Die Erstellung der Suchmaschinen bis die Ergebnisse da sind mit Unterfunktionen */ - public function createSearchEngines(Request $request, &$timings) + public function createSearchEngines(Request $request) { - if (!empty($timings)) { - $timings["createSearchEngines"]["start"] = microtime(true) - $timings["starttime"]; - } - # Wenn es kein Suchwort gibt if (!$request->filled("eingabe") || $this->q === "") { return; @@ -538,16 +518,8 @@ class MetaGer $sumas[$sumaName] = $this->sumaFile->sumas->{$sumaName}; } - if (!empty($timings)) { - $timings["createSearchEngines"]["created engine array"] = microtime(true) - $timings["starttime"]; - } - $this->removeAdsFromListIfAdfree($sumas); - if (!empty($timings)) { - $timings["createSearchEngines"]["removed ads"] = microtime(true) - $timings["starttime"]; - } - foreach ($sumas as $sumaName => $suma) { # Check if this engine is disabled and can't be used $disabled = empty($suma->disabled) ? false : $suma->disabled; @@ -601,10 +573,6 @@ class MetaGer } } - if (!empty($timings)) { - $timings["createSearchEngines"]["filtered invalid engines"] = microtime(true) - $timings["starttime"]; - } - # Include Yahoo Ads if Yahoo is not enabled as a searchengine if (!$this->apiAuthorized && $this->fokus != "bilder" && empty($this->enabledSearchengines["yahoo"]) && isset($this->sumaFile->sumas->{"yahoo-ads"})) { $this->enabledSearchengines["yahoo-ads"] = $this->sumaFile->sumas->{"yahoo-ads"}; @@ -629,9 +597,6 @@ class MetaGer $this->errors[] = $error; } $this->setEngines($request); - if (!empty($timings)) { - $timings["createSearchEngines"]["saved engines"] = microtime(true) - $timings["starttime"]; - } } private function removeAdsFromListIfAdfree(&$sumas) @@ -670,25 +635,15 @@ class MetaGer } } - public function startSearch(&$timings) + public function startSearch() { - if (!empty($timings)) { - $timings["startSearch"]["start"] = microtime(true) - $timings["starttime"]; - } - # Check all engines for Cached responses $this->checkCache(); - if (!empty($timings)) { - $timings["startSearch"]["cache checked"] = microtime(true) - $timings["starttime"]; - } - # Wir starten alle Suchen + /** @var Searchengine $engine */ foreach ($this->engines as $engine) { - $engine->startSearch($this, $timings); - } - if (!empty($timings)) { - $timings["startSearch"]["searches started"] = microtime(true) - $timings["starttime"]; + $engine->startSearch(); } } diff --git a/metager/app/Models/Adgoal.php b/metager/app/Models/Adgoal.php index 73418ce78..bdf4d427d 100644 --- a/metager/app/Models/Adgoal.php +++ b/metager/app/Models/Adgoal.php @@ -39,7 +39,6 @@ class Adgoal */ public function __construct(&$metager) { - $this->startTime = microtime(true); $publicKey = config("metager.metager.adgoal.public_key"); $privateKey = config("metager.metager.adgoal.private_key"); if ($publicKey === false) { @@ -210,8 +209,6 @@ class Adgoal } } - $requestTime = microtime(true) - $this->startTime; - \App\PrometheusExporter::Duration($requestTime, "adgoal"); $this->finished = true; } } diff --git a/metager/app/Models/Searchengine.php b/metager/app/Models/Searchengine.php index 31371721b..0c1d97a7f 100644 --- a/metager/app/Models/Searchengine.php +++ b/metager/app/Models/Searchengine.php @@ -114,17 +114,9 @@ abstract class Searchengine } # Prüft, ob die Suche bereits gecached ist, ansonsted wird sie als Job dispatched - public function startSearch(\App\MetaGer $metager, &$timings) + public function startSearch() { - if (!empty($timings)) { - $timings["startSearch"][$this->name]["start"] = microtime(true) - $timings["starttime"]; - } - if (!$this->cached) { - if (!empty($timings)) { - $timings["startSearch"][$this->name]["checked cache"] = microtime(true) - $timings["starttime"]; - } - // We need to submit a action that one of our workers can understand // The missions are submitted to a redis queue in the following string format // <ResultHash>;<URL to fetch> @@ -160,17 +152,11 @@ abstract class Searchengine // Since each Searcher is dedicated to one specific search engine // each Searcher has it's own queue lying under the redis key <name>.queue Redis::rpush(\App\MetaGer::FETCHQUEUE_KEY, $mission); - if (!empty($timings)) { - $timings["startSearch"][$this->name]["pushed job"] = microtime(true) - $timings["starttime"]; - } // The request is not cached and will be submitted to the searchengine // We need to check if the number of requests to this engine are limited if (!empty($this->engine->{"monthly-requests"})) { Redis::incr("monthlyRequests:" . $this->name); - if (!empty($timings)) { - $timings["startSearch"][$this->name]["increased monthly requests"] = microtime(true) - $timings["starttime"]; - } } } } diff --git a/metager/app/Providers/MetaGerProvider.php b/metager/app/Providers/MetaGerProvider.php index 5130baf49..b05b727f9 100644 --- a/metager/app/Providers/MetaGerProvider.php +++ b/metager/app/Providers/MetaGerProvider.php @@ -6,6 +6,7 @@ use App\MetaGer; use App\QueryLogger; use Illuminate\Support\Facades\App; use Illuminate\Support\ServiceProvider; +use Illuminate\Contracts\Support\DeferrableProvider; use App\QueryTimer; class MetaGerProvider extends ServiceProvider @@ -47,4 +48,13 @@ class MetaGerProvider extends ServiceProvider return new QueryTimer(); }); } + + // public function provides() + // { + // return [ + // MetaGer::class, + // QueryLogger::class, + // QueryTimer::class, + // ]; + // } } diff --git a/metager/app/QueryTimer.php b/metager/app/QueryTimer.php index a32d09761..8a7688a29 100644 --- a/metager/app/QueryTimer.php +++ b/metager/app/QueryTimer.php @@ -2,6 +2,8 @@ namespace App; +use \Exception; + class QueryTimer { private $start_time; @@ -19,11 +21,34 @@ class QueryTimer */ public function observeStart(String $name) { - if (!empty($timings[$name])) { + if (!empty($this->timings[$name])) { throw new Exception("Start Time for the event $name already registered"); } $this->timings[$name]["start"] = microtime(true); - dd($this->timings); + } + + /** + * Observes a end for a given name (Typically a function) + * It will store the name together with the current time + */ + public function observeEnd(String $name) + { + if (empty($this->timings[$name]["start"])) { + throw new Exception("Start Time for the event $name has not been registered yet"); + } + + $this->timings[$name]["end"] = microtime(true); + + PrometheusExporter::Duration($this->timings[$name]["end"] - $this->timings[$name]["start"], $name); + } + + /** + * Observes the total request time from start to finish + */ + public function observeTotal() + { + $total_time = \microtime(true) - $this->start_time; + PrometheusExporter::Duration($total_time, "Search_Total"); } } -- GitLab