Added analysis optional setting to compute statistics on text snippets

Thus producing some basic stats on processing times for snippets
generation and counts on snippets per source type.

5 files changed, 254 insertions, 19 deletions

diff --git a/source/net/yacy/search/Switchboard.java b/source/net/yacy/search/Switchboard.java
index 3cd616cac..5134bcb45 100644
--- a/source/net/yacy/search/Switchboard.java
+++ b/source/net/yacy/search/Switchboard.java
@@ -225,6 +225,7 @@ import net.yacy.search.ranking.RankingProfile;
 import net.yacy.search.schema.CollectionConfiguration;
 import net.yacy.search.schema.CollectionSchema;
 import net.yacy.search.schema.WebgraphConfiguration;
+import net.yacy.search.snippet.TextSnippet;
 import net.yacy.server.serverCore;
 import net.yacy.server.serverSwitch;
 import net.yacy.server.http.RobotsTxtConfig;
@@ -959,6 +960,9 @@ public final class Switchboard extends serverSwitch {
 
         // generate snippets cache
         this.log.config("Initializing Snippet Cache");
+        
+		TextSnippet.statistics.setEnabled(getConfigBool(SwitchboardConstants.DEBUG_SNIPPETS_STATISTICS_ENABLED,
+				SwitchboardConstants.DEBUG_SNIPPETS_STATISTICS_ENABLED_DEFAULT));
 
         // init the wiki
         wikiParser = new WikiCode();
diff --git a/source/net/yacy/search/SwitchboardConstants.java b/source/net/yacy/search/SwitchboardConstants.java
index 5f150fee6..f74d204cb 100644
--- a/source/net/yacy/search/SwitchboardConstants.java
+++ b/source/net/yacy/search/SwitchboardConstants.java
@@ -374,6 +374,12 @@ public final class SwitchboardConstants {
     /** when set to true : do not use dht, search local peer in a shortcut to the own server */
     public static final String DEBUG_SEARCH_REMOTE_SOLR_TESTLOCAL= "debug.search.remote.solr.testlocal";
     
+    /** Key of the setting controlling whether text snippets statistics should be computed */
+    public static final String DEBUG_SNIPPETS_STATISTICS_ENABLED = "debug.snippets.statistics.enabled";
+    
+    /** Default value for the setting controlling whether text snippets statistics should be computed */
+    public static final boolean DEBUG_SNIPPETS_STATISTICS_ENABLED_DEFAULT = false;
+    
     /**
      * <p><code>public static final String <strong>WORDCACHE_MAX_COUNT</strong> = "wordCacheMaxCount"</code></p>
      * <p>Name of the setting how many words the word-cache (or DHT-Out cache) shall contain maximal. Indexing pages if the
diff --git a/source/net/yacy/search/query/SearchEvent.java b/source/net/yacy/search/query/SearchEvent.java
index 186bce696..0acdfd823 100644
--- a/source/net/yacy/search/query/SearchEvent.java
+++ b/source/net/yacy/search/query/SearchEvent.java
@@ -1874,7 +1874,7 @@ public final class SearchEvent implements ScoreMapUpdatesListener {
             LinkedHashSet<String> solrsnippetlines = this.snippets.remove(ASCII.String(node.hash())); // we can remove this because it's used only once
             if (solrsnippetlines != null && solrsnippetlines.size() > 0) {
                 OpensearchResponseWriter.removeSubsumedTitle(solrsnippetlines, node.dc_title());
-                final TextSnippet solrsnippet = new TextSnippet(node.hash(), OpensearchResponseWriter.getLargestSnippet(solrsnippetlines), true, ResultClass.SOURCE_CACHE, "");
+                final TextSnippet solrsnippet = new TextSnippet(node.hash(), OpensearchResponseWriter.getLargestSnippet(solrsnippetlines), true, ResultClass.SOURCE_SOLR, "");
                 final TextSnippet yacysnippet = new TextSnippet(this.loader,
                         node,
                         this.query.getQueryGoal().getIncludeHashes(),
diff --git a/source/net/yacy/search/snippet/TextSnippet.java b/source/net/yacy/search/snippet/TextSnippet.java
index c04d73958..5da937dce 100644
--- a/source/net/yacy/search/snippet/TextSnippet.java
+++ b/source/net/yacy/search/snippet/TextSnippet.java
@@ -60,6 +60,7 @@ import net.yacy.search.query.QueryGoal;
 

 public class TextSnippet implements Comparable<TextSnippet>, Comparator<TextSnippet> {

 

+	/** The maximum number of sinppet entries in the cache */

     private static final int MAX_CACHE = 1000;

 

 

@@ -111,11 +112,19 @@ public class TextSnippet implements Comparable<TextSnippet>, Comparator<TextSnip
     }

 

     public static final Cache snippetsCache = new Cache();

+    

+    /** Handle statistics on TextSnippet processing */

+    public static final TextSnippetStatistics statistics = new TextSnippetStatistics();

 

     public static enum ResultClass {

+    	/** Snippet provided by Solr */

+        SOURCE_SOLR(false),

+    	/** Snippet retrieved from snippets cache or computed from cached document */

         SOURCE_CACHE(false),

         SOURCE_FILE(false),

+        /** Snippet computed from the original document fetched and parsed */

         SOURCE_WEB(false),

+        /** Snippet computed by YaCy from document metadata */

         SOURCE_METADATA(false),

         ERROR_NO_HASH_GIVEN(true),

         ERROR_SOURCE_LOADING(true),

@@ -150,7 +159,8 @@ public class TextSnippet implements Comparable<TextSnippet>, Comparator<TextSnip
             final boolean isMarked,

             final ResultClass errorCode,

             final String errortext) {

-        init(urlhash, line, isMarked, errorCode, errortext);

+    	long beginTime = System.currentTimeMillis();

+        init(urlhash, line, isMarked, errorCode, errortext, beginTime);

     }

 

     public TextSnippet(

@@ -161,23 +171,24 @@ public class TextSnippet implements Comparable<TextSnippet>, Comparator<TextSnip
             final boolean pre,

             final int snippetMaxLength,

             final boolean reindexing) {

+    	long beginTime = System.currentTimeMillis();

         // heise = "0OQUNU3JSs05"

         

         final DigestURL url = row.url();

         if (queryhashes.isEmpty()) {

             //System.out.println("found no queryhashes for URL retrieve " + url);

-            init(url.hash(), null, false, ResultClass.ERROR_NO_HASH_GIVEN, "no query hashes given");

+            init(url.hash(), null, false, ResultClass.ERROR_NO_HASH_GIVEN, "no query hashes given", beginTime);

             return;

         }

 

         // try to get snippet from snippetCache

-        final ResultClass source = ResultClass.SOURCE_CACHE;

+        ResultClass source = ResultClass.SOURCE_CACHE;

         final String wordhashes = RemoteSearch.set2string(queryhashes);

         final String urls = ASCII.String(url.hash());

         final String snippetLine = snippetsCache.get(wordhashes, urls);

         if (snippetLine != null) {

             // found the snippet

-            init(url.hash(), snippetLine, false, source, null);

+            init(url.hash(), snippetLine, false, source, null, beginTime);

             return;

         }

 

@@ -228,7 +239,7 @@ public class TextSnippet implements Comparable<TextSnippet>, Comparator<TextSnip
             }

             if (sentences == null) {

                 // not found the snippet

-                init(url.hash(), null, false, ResultClass.SOURCE_METADATA, null);

+                init(url.hash(), null, false, ResultClass.SOURCE_METADATA, null, beginTime);

                 return;

             }

 

@@ -238,7 +249,7 @@ public class TextSnippet implements Comparable<TextSnippet>, Comparator<TextSnip
                     textline = tsr.getSnippet();

                     remainingHashes = tsr.getRemainingWords();

                 } catch (final UnsupportedOperationException e) {

-                    init(url.hash(), null, false, ResultClass.ERROR_NO_MATCH, "snippet extractor failed:" + e.getMessage());

+                    init(url.hash(), null, false, ResultClass.ERROR_NO_MATCH, "snippet extractor failed:" + e.getMessage(), beginTime);

                     return;

                 }

             }

@@ -282,7 +293,7 @@ public class TextSnippet implements Comparable<TextSnippet>, Comparator<TextSnip
                     }

                 }

             }

-            init(url.hash(), textline.length() > 0 ? textline : this.line, false, ResultClass.SOURCE_METADATA, null);

+            init(url.hash(), textline.length() > 0 ? textline : this.line, false, ResultClass.SOURCE_METADATA, null, beginTime);

             return;

         }

         sentences = null; // we don't need this here any more

@@ -298,19 +309,19 @@ public class TextSnippet implements Comparable<TextSnippet>, Comparator<TextSnip
         if (response == null) {

             // in case that we did not get any result we can still return a success when we are not allowed to go online

             if (cacheStrategy == null || cacheStrategy.mustBeOffline()) {

-                init(url.hash(), null, false, ResultClass.ERROR_SOURCE_LOADING, "omitted network load (not allowed), no cache entry");

+                init(url.hash(), null, false, ResultClass.ERROR_SOURCE_LOADING, "omitted network load (not allowed), no cache entry", beginTime);

                 return;

             }

 

             // if it is still not available, report an error

-            init(url.hash(), null, false, ResultClass.ERROR_RESOURCE_LOADING, "error loading resource from net, no cache entry");

+            init(url.hash(), null, false, ResultClass.ERROR_RESOURCE_LOADING, "error loading resource from net, no cache entry", beginTime);

             return;

         }

 

         if (!response.fromCache()) {

             // place entry on indexing queue

             Switchboard.getSwitchboard().toIndexer(response);

-            this.resultStatus = ResultClass.SOURCE_WEB;

+            source = ResultClass.SOURCE_WEB;

         }

 

         // parse the document to get all sentenced; available for snippet computation

@@ -318,11 +329,11 @@ public class TextSnippet implements Comparable<TextSnippet>, Comparator<TextSnip
         try {

             document = Document.mergeDocuments(response.url(), response.getMimeType(), response.parse());

         } catch (final Parser.Failure e) {

-            init(url.hash(), null, false, ResultClass.ERROR_PARSER_FAILED, e.getMessage()); // cannot be parsed

+            init(url.hash(), null, false, ResultClass.ERROR_PARSER_FAILED, e.getMessage(), beginTime); // cannot be parsed

             return;

         }

         if (document == null) {

-            init(url.hash(), null, false, ResultClass.ERROR_PARSER_FAILED, "parser error/failed"); // cannot be parsed

+            init(url.hash(), null, false, ResultClass.ERROR_PARSER_FAILED, "parser error/failed", beginTime); // cannot be parsed

             return;

         }

 

@@ -331,7 +342,7 @@ public class TextSnippet implements Comparable<TextSnippet>, Comparator<TextSnip
         document.close();

 

         if (sentences == null) {

-            init(url.hash(), null, false, ResultClass.ERROR_PARSER_NO_LINES, "parser returned no sentences");

+            init(url.hash(), null, false, ResultClass.ERROR_PARSER_NO_LINES, "parser returned no sentences", beginTime);

             return;

         }

 

@@ -340,20 +351,20 @@ public class TextSnippet implements Comparable<TextSnippet>, Comparator<TextSnip
             textline = tsr.getSnippet();

             remainingHashes =  tsr.getRemainingWords();

         } catch (final UnsupportedOperationException e) {

-            init(url.hash(), null, false, ResultClass.ERROR_NO_MATCH, "snippet extractor failed:" + e.getMessage());

+            init(url.hash(), null, false, ResultClass.ERROR_NO_MATCH, "snippet extractor failed:" + e.getMessage(), beginTime);

             return;

         }

         sentences = null;

 

         if (textline == null || !remainingHashes.isEmpty()) {

-            init(url.hash(), null, false, ResultClass.ERROR_NO_MATCH, "no matching snippet found");

+            init(url.hash(), null, false, ResultClass.ERROR_NO_MATCH, "no matching snippet found", beginTime);

             return;

         }

         if (textline.length() > snippetMaxLength) textline = textline.substring(0, snippetMaxLength);

 

         // finally store this snippet in our own cache

         snippetsCache.put(wordhashes, urls, textline);

-        init(url.hash(), textline, false, source, null);

+        init(url.hash(), textline, false, source, null, beginTime);

     }

 

     /**

@@ -364,18 +375,21 @@ public class TextSnippet implements Comparable<TextSnippet>, Comparator<TextSnip
      * @param isMarked true if query words already marked in input text

      * @param errorCode

      * @param errortext

+     * @param beginTime the time in milliseconds when TextSnippet creation started

      */

     private void init(

             final byte[] urlhash,

             final String line,

             final boolean isMarked,

             final ResultClass errorCode,

-            final String errortext) {

+            final String errortext,

+            final long beginTime) {

         this.urlhash = urlhash;

         this.line = line;

         this.isMarked = isMarked;

         this.resultStatus = errorCode;

         this.error = errortext;

+		TextSnippet.statistics.addTextSnippetStatistics(System.currentTimeMillis() - beginTime, this.resultStatus);

     }

 

     /**

@@ -588,5 +602,4 @@ public class TextSnippet implements Comparable<TextSnippet>, Comparator<TextSnip
         }

         for (final byte[] b : o) queryhashes.remove(b);

     }

-

 }

diff --git a/source/net/yacy/search/snippet/TextSnippetStatistics.java b/source/net/yacy/search/snippet/TextSnippetStatistics.java
new file mode 100644
index 000000000..9af6a5514
--- /dev/null
+++ b/source/net/yacy/search/snippet/TextSnippetStatistics.java
@@ -0,0 +1,212 @@
+// TextSnippetStatistics.java
+// ---------------------------
+// Copyright 2018 by luccioman; https://github.com/luccioman
+//
+// This is a part of YaCy, a peer-to-peer based web search engine
+//
+// LICENSE
+//
+// This program is free software; you can redistribute it and/or modify
+// it under the terms of the GNU General Public License as published by
+// the Free Software Foundation; either version 2 of the License, or
+// (at your option) any later version.
+//
+// This program is distributed in the hope that it will be useful,
+// but WITHOUT ANY WARRANTY; without even the implied warranty of
+// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+// GNU General Public License for more details.
+//
+// You should have received a copy of the GNU General Public License
+// along with this program; if not, write to the Free Software
+// Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
+
+package net.yacy.search.snippet;
+
+import java.util.concurrent.atomic.AtomicBoolean;
+import java.util.concurrent.atomic.AtomicLong;
+import java.util.function.LongBinaryOperator;
+
+import net.yacy.search.SwitchboardConstants;
+import net.yacy.search.snippet.TextSnippet.ResultClass;
+
+/**
+ * Handle statistics on TextSnippet processing.
+ */
+public class TextSnippetStatistics {
+
+	/** Total number of TextSnippet instances created since last JVM start */
+	private AtomicLong totalSnippets = new AtomicLong(0);
+
+	/**
+	 * Total number of TextSnippet instances with resultStatus of type fail created
+	 * since last JVM start
+	 */
+	private AtomicLong totalFailures = new AtomicLong(0);
+
+	/**
+	 * Total number of TextSnippet instances with resultStatus of type
+	 * ResultClass.SOURCE_DOLR created since last JVM start
+	 */
+	private AtomicLong totalFromSolr = new AtomicLong(0);
+
+	/**
+	 * Total number of TextSnippet instances with resultStatus of type
+	 * ResultClass.SOURCE_CACHE created since last JVM start
+	 */
+	private AtomicLong totalFromCache = new AtomicLong(0);
+
+	/**
+	 * Total number of TextSnippet instances with resultStatus of type
+	 * ResultClass.SOURCE_WEB created since last JVM start
+	 */
+	private AtomicLong totalFromWeb = new AtomicLong(0);
+
+	/**
+	 * Total number of TextSnippet instances with resultStatus of type
+	 * ResultClass.SOURCE_METADATA created since last JVM start
+	 */
+	private AtomicLong totalFromMetadata = new AtomicLong(0);
+
+	/**
+	 * Total time (in milliseconds) spent in TextSnippet initialization since last
+	 * JVM start
+	 */
+	private AtomicLong totalInitTime = new AtomicLong(0);
+
+	/**
+	 * Maximum time (in milliseconds) spent in a single TextSnippet initialization
+	 * since last JVM start
+	 */
+	private AtomicLong maxInitTime = new AtomicLong(0);
+
+	/**
+	 * Statistics are effectively computed and stored only when this boolean is true
+	 */
+	private AtomicBoolean enabled = new AtomicBoolean(SwitchboardConstants.DEBUG_SNIPPETS_STATISTICS_ENABLED_DEFAULT);
+
+	/**
+	 * @return the total number of TextSnippet instances created since last JVM
+	 *         start
+	 */
+	public long getTotalSnippets() {
+		return this.totalSnippets.get();
+	}
+
+	/**
+	 * @return the total number of TextSnippet instances with resultStatus of type
+	 *         fail created since last JVM start
+	 */
+	public long getTotalFailures() {
+		return this.totalFailures.get();
+	}
+
+	/**
+	 * @return the total number of TextSnippet instances with resultStatus of type
+	 *         ResultClass.SOURCE_SOLR created since last JVM start
+	 */
+	public long getTotalFromSolr() {
+		return this.totalFromSolr.get();
+	}
+
+	/**
+	 * @return the total number of TextSnippet instances with resultStatus of type
+	 *         ResultClass.SOURCE_CACHE created since last JVM start
+	 */
+	public long getTotalFromCache() {
+		return this.totalFromCache.get();
+	}
+
+	/**
+	 * @return the total number of TextSnippet instances with resultStatus of type
+	 *         ResultClass.SOURCE_METADATA created since last JVM start
+	 */
+	public long getTotalFromMetadata() {
+		return this.totalFromMetadata.get();
+	}
+
+	/**
+	 * @return the total number of TextSnippet instances with resultStatus of type
+	 *         ResultClass.SOURCE_WEB created since last JVM start
+	 */
+	public long getTotalFromWeb() {
+		return this.totalFromWeb.get();
+	}
+
+	/**
+	 * Update statistics after a new TextSnippet instance has been initialized. Do
+	 * nothing when text snippet statistics are not enabled.
+	 * 
+	 * @param initTime
+	 *            the time in milliseconds used for the snippet initialization
+	 * @param resultStatus
+	 *            the snippet result status.
+	 */
+	public void addTextSnippetStatistics(final long initTime, final ResultClass resultStatus) {
+		if (this.enabled.get() && resultStatus != null) {
+			this.totalSnippets.incrementAndGet();
+			this.totalInitTime.addAndGet(initTime);
+			this.maxInitTime.accumulateAndGet(initTime, new LongBinaryOperator() {
+				
+				@Override
+				public long applyAsLong(long currentValue, long updateValue) {
+					return currentValue < updateValue ? updateValue : currentValue;
+				}
+			});
+			
+			if (resultStatus != null) {
+				switch (resultStatus) {
+				case SOURCE_SOLR:
+					this.totalFromSolr.incrementAndGet();
+					break;
+				case SOURCE_CACHE:
+					this.totalFromCache.incrementAndGet();
+					break;
+				case SOURCE_METADATA:
+					this.totalFromMetadata.incrementAndGet();
+					break;
+				case SOURCE_WEB:
+					this.totalFromWeb.incrementAndGet();
+					break;
+				default:
+					if (resultStatus.fail()) {
+						this.totalFailures.incrementAndGet();
+					}
+					break;
+				}
+			}
+		}
+
+	}
+
+	/**
+	 * @return the total time (in milliseconds) spent in TextSnippet initialization
+	 *         since last JVM start
+	 */
+	public long getTotalInitTime() {
+		return this.totalInitTime.get();
+	}
+
+	/**
+	 * @return the maximum time (in milliseconds) spent in a single TextSnippet
+	 *         initialization since last JVM start
+	 */
+	public long getMaxInitTime() {
+		return this.totalInitTime.get();
+	}
+
+	/**
+	 * @return true when statistics are effectively computed and stored
+	 */
+	public boolean isEnabled() {
+		return this.enabled.get();
+	}
+
+	/**
+	 * @param newValue
+	 *            set to true to effectively compute and store statistics
+	 */
+	public void setEnabled(final boolean newValue) {
+		this.enabled.set(newValue);
+	}
+
+}