Merge branch '934-implement-timing-output' into 'development'

Resolve "Implement Timing output"

Closes #934

See merge request !1507

app/Http/Controllers/MetaGerSearch.php

@@ -11,8 +11,13 @@ use View;
 
 class MetaGerSearch extends Controller
 {
-    public function search(Request $request, MetaGer $metager)
+
+    public function search(Request $request, MetaGer $metager, $timing = false)
     {
+        $timings = null;
+        if ($timing) {
+            $timings = ['starttime' => microtime(true)];
+        }
         $time = microtime(true);
         $spamEntries = [];
         if (file_exists(config_path('spam.txt'))) {
@@ -34,9 +39,15 @@ class MetaGerSearch extends Controller
 
         # Mit gelieferte Formulardaten parsen und abspeichern:
         $metager->parseFormData($request);
+        if (!empty($timings)) {
+            $timings["parseFormData"] = microtime(true) - $time;
+        }
 
         # Nach Spezialsuchen überprüfen:
         $metager->checkSpecialSearches($request);
+        if (!empty($timings)) {
+            $timings["checkSpecialSearches"] = microtime(true) - $time;
+        }
 
         if (Cache::has('spam.' . $metager->getFokus() . "." . md5($metager->getQ()))) {
             return response(Cache::get('spam.' . $metager->getFokus() . "." . md5($metager->getEingabe())));
@@ -44,24 +55,43 @@ class MetaGerSearch extends Controller
 
         # Die Quicktips als Job erstellen
         $quicktips = $metager->createQuicktips();
+        if (!empty($timings)) {
+            $timings["createQuicktips"] = microtime(true) - $time;
+        }
 
         # Suche für alle zu verwendenden Suchmaschinen als Job erstellen,
         # auf Ergebnisse warten und die Ergebnisse laden
-        $metager->createSearchEngines($request);
+        $metager->createSearchEngines($request, $timings);
 
-        $metager->startSearch();
+        $metager->startSearch($timings);
 
         $metager->waitForMainResults();
+        if (!empty($timings)) {
+            $timings["waitForMainResults"] = microtime(true) - $time;
+        }
 
         $metager->retrieveResults();
+        if (!empty($timings)) {
+            $timings["retrieveResults"] = microtime(true) - $time;
+        }
 
         # Versuchen die Ergebnisse der Quicktips zu laden
         $quicktipResults = $quicktips->loadResults();
+        if (!empty($timings)) {
+            $timings["loadResults"] = microtime(true) - $time;
+        }
+
         # Alle Ergebnisse vor der Zusammenführung ranken:
         $metager->rankAll();
+        if (!empty($timings)) {
+            $timings["rankAll"] = microtime(true) - $time;
+        }
 
         # Ergebnisse der Suchmaschinen kombinieren:
         $metager->prepareResults();
+        if (!empty($timings)) {
+            $timings["prepareResults"] = microtime(true) - $time;
+        }
 
         $finished = true;
         foreach ($metager->getEngines() as $engine) {
@@ -72,6 +102,9 @@ class MetaGerSearch extends Controller
         }
 
         Cache::put("loader_" . $metager->getSearchUid(), $metager->getEngines(), 60 * 60);
+        if (!empty($timings)) {
+            $timings["Filled resultloader Cache"] = microtime(true) - $time;
+        }
 
         # Die Ausgabe erstellen:
         $resultpage = $metager->createView($quicktipResults);
@@ -84,9 +117,25 @@ class MetaGerSearch extends Controller
                 Cache::put('spam.' . $metager->getFokus() . "." . md5($metager->getEingabe()), $resultpage->render(), 604800);
             }
         }
+        if (!empty($timings)) {
+            $timings["createView"] = microtime(true) - $time;
+        }
+
+        if ($timings) {
+            dd($timings);
+        }
+
         return $resultpage;
     }
 
+    public function searchTimings(Request $request, MetaGer $metager)
+    {
+        $request->merge([
+            'eingabe' => "Hannover",
+        ]);
+        return $this->search($request, $metager, true);
+    }
+
     public function loadMore(Request $request)
     {
         /**

app/MetaGer.php

@@ -473,8 +473,12 @@ class MetaGer
      * Die Erstellung der Suchmaschinen bis die Ergebnisse da sind mit Unterfunktionen
      */
 
-    public function createSearchEngines(Request $request)
+    public function createSearchEngines(Request $request, &$timings)
     {
+        if (!empty($timings)) {
+            $timings["createSearchEngines"]["start"] = microtime(true) - $timings["starttime"];
+        }
+
         # Wenn es kein Suchwort gibt
         if (!$request->filled("eingabe") || $this->q === "") {
             return;
@@ -495,8 +499,16 @@ 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;
@@ -550,6 +562,10 @@ 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"};
@@ -574,6 +590,10 @@ class MetaGer
             $this->errors[] = $error;
         }
         $this->setEngines($request);
+        if (!empty($timings)) {
+            $timings["createSearchEngines"]["saved engines"] = microtime(true) - $timings["starttime"];
+        }
+
     }
 
     private function removeAdsFromListIfAdfree(&$sumas)
@@ -612,12 +632,38 @@ class MetaGer
         }
     }
 
-    public function startSearch()
+    public function startSearch(&$timings)
     {
+        if (!empty($timings)) {
+            $timings["startSearch"]["start"] = microtime(true) - $timings["starttime"];
+        }
+
+        # Check all engines for Cached responses
+        if ($this->canCache()) {
+            $keys = [];
+            foreach ($this->engines as $engine) {
+                $keys[] = $engine->hash;
+            }
+            $cacheValues = Cache::many($keys);
+            foreach ($this->engines as $engine) {
+                if ($cacheValues[$engine->hash] !== null) {
+                    $engine->cached = true;
+                    $engine->retrieveResults($this, $cacheValues[$engine->hash]);
+                }
+            }
+        }
+        if (!empty($timings)) {
+            $timings["startSearch"]["cache checked"] = microtime(true) - $timings["starttime"];
+        }
+
         # Wir starten alle Suchen
         foreach ($this->engines as $engine) {
-            $engine->startSearch($this);
+            $engine->startSearch($this, $timings);
+        }
+        if (!empty($timings)) {
+            $timings["startSearch"]["searches started"] = microtime(true) - $timings["starttime"];
         }
+
     }
 
     # Spezielle Suchen und Sumas
@@ -788,19 +834,20 @@ class MetaGer
         $mainEngines = $this->sumaFile->foki->{$this->fokus}->main;
         foreach ($mainEngines as $mainEngine) {
             foreach ($engines as $engine) {
-                if ($engine->name === $mainEngine) {
+                if ($engine->name === $mainEngine && !$engine->loaded) {
                     $enginesToWaitFor[] = $engine;
                 }
             }
         }
 
         $timeStart = microtime(true);
+
         $answered = [];
         $results = null;
 
         # If there is no main searchengine to wait for or if the only main engine is yahoo-ads we will define a timeout of 1s
         $forceTimeout = null;
-        if (sizeof($enginesToWaitFor) === 0 || (sizeof($enginesToWaitFor) === 1 && $enginesToWaitFor[0]->name === "yahoo-ads")) {
+        if (sizeof($enginesToWaitFor) === 1 && $enginesToWaitFor[0]->name === "yahoo-ads") {
             $forceTimeout = 1;
         }
 
@@ -812,30 +859,13 @@ class MetaGer
                     break;
                 }
             }
+
             if ((microtime(true) - $timeStart) >= 2) {
                 break;
             } else {
                 usleep(50 * 1000);
             }
         }
-
-        # Now we can add an entry to Redis which defines the starting time and how many engines should answer this request
-        /*
-    $pipeline = $redis->pipeline();
-    $pipeline->hset($this->getRedisEngineResult() . "status", "startTime", $timeStart);
-    $pipeline->hset($this->getRedisEngineResult() . "status", "engineCount", sizeof($engines));
-    $pipeline->hset($this->getRedisEngineResult() . "status", "engineDelivered", sizeof($answered));
-    # Add the cached engines as answered
-    foreach ($engines as $engine) {
-    if ($engine->cached) {
-    $pipeline->hincrby($this->getRedisEngineResult() . "status", "engineDelivered", 1);
-    $pipeline->hincrby($this->getRedisEngineResult() . "status", "engineAnswered", 1);
-    }
-    }
-    foreach ($answered as $engine) {
-    $pipeline->hset($this->getRedisEngineResult() . $engine, "delivered", "1");
-    }
-    $pipeline->execute();*/
     }
 
     public function retrieveResults()

app/Models/Searchengine.php

@@ -3,7 +3,6 @@
 namespace App\Models;
 
 use App\MetaGer;
-use Cache;
 use Illuminate\Support\Facades\Redis;
 
 abstract class Searchengine
@@ -105,12 +104,17 @@ abstract class Searchengine
     {}
 
     # Prüft, ob die Suche bereits gecached ist, ansonsted wird sie als Job dispatched
-    public function startSearch(\App\MetaGer $metager)
+    public function startSearch(\App\MetaGer $metager, &$timings)
     {
-        if ($this->canCache && Cache::has($this->hash)) {
-            $this->cached = true;
-            $this->retrieveResults($metager, true);
-        } else {
+        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>
@@ -144,10 +148,17 @@ 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"];
+                }
             }
         }
     }
@@ -171,15 +182,13 @@ abstract class Searchengine
     }
 
     # Fragt die Ergebnisse von Redis ab und lädt Sie
-    public function retrieveResults(MetaGer $metager)
+    public function retrieveResults(MetaGer $metager, $body = null)
     {
         if ($this->loaded) {
             return true;
         }
 
-        $body = null;
         if ($this->cached) {
-            $body = Cache::get($this->hash);
             if ($body === "no-result") {
                 $body = "";
             }

chart/templates/deployment.yaml

@@ -38,9 +38,6 @@ spec:
       - name: mglogs-persistent-storage
         persistentVolumeClaim:
           claimName: mglogs
-      - name: mgcache-persistent-storage
-        persistentVolumeClaim:
-          claimName: mgcache
       containers:
       - name: {{ .Chart.Name }}
         image: "{{ .Values.image.repository }}:{{ .Values.image.tag }}"
@@ -105,9 +102,6 @@ spec:
         - name: mglogs-persistent-storage
           mountPath: /html/storage/logs/metager
           readOnly: false
-        - name: mgcache-persistent-storage
-          mountPath: /html/storage/framework/cache
-          readOnly: false
         resources:
 {{ toYaml .Values.resources | indent 12 }}
 {{- end -}}

routes/web.php

@@ -170,6 +170,7 @@ Route::group(
         Route::group(['middleware' => ['auth.basic'], 'prefix' => 'admin'], function () {
             Route::get('/', 'AdminInterface@index');
             Route::match(['get', 'post'], 'count', 'AdminInterface@count');
+            Route::get('timings', 'MetaGerSearch@searchTimings');
             Route::get('count/graphtoday.svg', 'AdminInterface@countGraphToday');
             Route::get('engine/stats.json', 'AdminInterface@engineStats');
             Route::get('check', 'AdminInterface@check');
@@ -181,6 +182,7 @@ Route::group(
         });
 
         Route::match(['get', 'post'], 'meta/meta.ger3', 'MetaGerSearch@search')->middleware('humanverification', 'useragentmaster');
+
         Route::get('meta/loadMore', 'MetaGerSearch@loadMore');
         Route::post('img/cat.jpg', 'HumanVerification@remove');
         Route::get('r/metager/{mm}/{pw}/{url}', ['as' => 'humanverification', 'uses' => 'HumanVerification@removeGet']);