QueryTimings are exported to prometheus

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)

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);
     }

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);
     }
 

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);
     }
 }

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);
     }
 }

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();
         }
     }
 

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;
     }
 }

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"];
-                }
             }
         }
     }

metager/app/Providers/MetaGerProvider.php

@@ -6,6 +6,7 @@ use App\MetaGer;
 use App\QueryLogger;
 use Illuminate\Support\Facades\App;