Refactor: Pull tracing into its own class

1 files changed, 39 insertions, 134 deletions

diff --git a/container-search/src/main/java/com/yahoo/search/Query.java b/container-search/src/main/java/com/yahoo/search/Query.java
index dcbda80ecab..e4f62f83e99 100644
--- a/container-search/src/main/java/com/yahoo/search/Query.java
+++ b/container-search/src/main/java/com/yahoo/search/Query.java
@@ -12,10 +12,10 @@ import com.yahoo.search.schema.SchemaInfo;
 import com.yahoo.search.dispatch.Dispatcher;
 import com.yahoo.search.federation.FederationSearcher;
 import com.yahoo.search.query.Model;
+import com.yahoo.search.query.Trace;
 import com.yahoo.search.query.ParameterParser;
 import com.yahoo.search.query.Presentation;
 import com.yahoo.search.query.Properties;
-import com.yahoo.search.query.QueryTree;
 import com.yahoo.search.query.Ranking;
 import com.yahoo.search.query.Select;
 import com.yahoo.search.query.SessionId;
@@ -50,14 +50,11 @@ import java.nio.ByteBuffer;
 import java.util.ArrayList;
 import java.util.Collections;
 import java.util.HashMap;
-import java.util.HashSet;
 import java.util.List;
 import java.util.Map;
 import java.util.Objects;
 import java.util.Set;
 import java.util.concurrent.TimeUnit;
-import java.util.logging.Level;
-import java.util.logging.Logger;
 
 /**
  * A search query containing all the information required to produce a Result.
@@ -72,7 +69,7 @@ import java.util.logging.Logger;
  * </ul>
  *
  * <p>
- * The properties has three sources
+ * The properties have three sources
  * <ol>
  * <li>They may be set in some Searcher component already executed for this Query - the properties acts as
  * a blackboard for communicating arbitrary objects between Searcher components.
@@ -130,6 +127,9 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
 
     }
 
+    /** The time this query was created */
+    private long startTime;
+
     //--------------  Query properties treated as fields in Query ---------------
 
     /** The offset from the most relevant hits found from this query */
@@ -138,9 +138,6 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
     /** The number of hits to return */
     private int hits = 10;
 
-    /** The query context level, 0 means no tracing */
-    private int traceLevel = 0;
-
     /** The query explain level, 0 means no explaining */
     private int explainLevel = 0;
 
@@ -181,12 +178,8 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
     /** The selection of where-clause and grouping */
     private Select select = new Select(this);
 
-    //---------------- Tracing ----------------------------------------------------
-
-    private static final Logger log = Logger.getLogger(Query.class.getName());
-
-    /** The time this query was created */
-    private long startTime;
+    /** How this query should be traced */
+    public Trace trace = new Trace(this);
 
     //---------------- Static property handling ------------------------------------
 
@@ -195,12 +188,15 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
 
     public static final CompoundName QUERY_PROFILE = new CompoundName("queryProfile");
     public static final CompoundName SEARCH_CHAIN = new CompoundName("searchChain");
-    public static final CompoundName TRACE_LEVEL = new CompoundName("traceLevel");
+
     public static final CompoundName EXPLAIN_LEVEL = new CompoundName("explainLevel");
     public static final CompoundName NO_CACHE = new CompoundName("noCache");
     public static final CompoundName GROUPING_SESSION_CACHE = new CompoundName("groupingSessionCache");
     public static final CompoundName TIMEOUT = new CompoundName("timeout");
 
+    /** @deprecated use Trace.LEVEL */
+    @Deprecated // TODO: Remove on Vespa 9
+    public static final CompoundName TRACE_LEVEL = new CompoundName("traceLevel");
 
     private static final QueryProfileType argumentType;
     static {
@@ -213,7 +209,6 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
         argumentType.addField(new FieldDescription(HITS.toString(), "integer", "hits count"));
         argumentType.addField(new FieldDescription(QUERY_PROFILE.toString(), "string"));
         argumentType.addField(new FieldDescription(SEARCH_CHAIN.toString(), "string"));
-        argumentType.addField(new FieldDescription(TRACE_LEVEL.toString(), "integer", "tracelevel"));
         argumentType.addField(new FieldDescription(EXPLAIN_LEVEL.toString(), "integer", "explainlevel"));
         argumentType.addField(new FieldDescription(NO_CACHE.toString(), "boolean", "nocache"));
         argumentType.addField(new FieldDescription(GROUPING_SESSION_CACHE.toString(), "boolean", "groupingSessionCache"));
@@ -225,6 +220,7 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
         argumentType.addField(new FieldDescription(Dispatcher.DISPATCH, new QueryProfileFieldType(Dispatcher.getArgumentType())));
         argumentType.addField(new FieldDescription(Ranking.RANKING, new QueryProfileFieldType(Ranking.getArgumentType())));
         argumentType.addField(new FieldDescription(Presentation.PRESENTATION, new QueryProfileFieldType(Presentation.getArgumentType())));
+        argumentType.addField(new FieldDescription(Trace.TRACE, new QueryProfileFieldType(Trace.getArgumentType())));
         argumentType.freeze();
     }
     public static QueryProfileType getArgumentType() { return argumentType; }
@@ -260,6 +256,7 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
         registry.register(Select.getArgumentType().unfrozen());
         registry.register(Ranking.getArgumentType().unfrozen());
         registry.register(Presentation.getArgumentType().unfrozen());
+        registry.register(Trace.getArgumentType().unfrozen());
         registry.register(DefaultProperties.argumentType.unfrozen());
     }
 
@@ -403,7 +400,7 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
         }
 
         properties().setParentQuery(this);
-        traceProperties();
+        trace.traceProperties();
     }
 
     public Query(Query query) {
@@ -478,59 +475,6 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
     public Properties properties() { return (Properties)super.properties(); }
 
     /**
-     * Traces how properties was resolved and from where. Done after the fact to avoid special handling
-     * of tracelevel, which is the property deciding whether this needs to be done
-     */
-    private void traceProperties() {
-        if (traceLevel == 0) return;
-        CompiledQueryProfile profile = null;
-        QueryProfileProperties profileProperties = properties().getInstance(QueryProfileProperties.class);
-        if (profileProperties != null)
-            profile = profileProperties.getQueryProfile();
-
-        if (profile == null)
-            trace("No query profile is used", false, 1);
-        else
-            trace("Using " + profile.toString(), false, 1);
-
-        if (traceLevel < 4) return;
-        StringBuilder b = new StringBuilder("Resolved properties:\n");
-        Set<String> mentioned = new HashSet<>();
-        for (Map.Entry<String,String> requestProperty : requestProperties().entrySet() ) {
-            Object resolvedValue = properties().get(requestProperty.getKey(), requestProperties());
-            if (resolvedValue == null && requestProperty.getKey().equals("queryProfile"))
-                resolvedValue = requestProperty.getValue();
-
-            b.append(requestProperty.getKey());
-            b.append(": ");
-            b.append(resolvedValue); // (may be null)
-            b.append(" (");
-
-            if (profile != null && ! profile.isOverridable(new CompoundName(requestProperty.getKey()), requestProperties()))
-                b.append("from query profile - unoverridable, ignoring request value");
-            else
-                b.append("from request");
-            b.append(")\n");
-            mentioned.add(requestProperty.getKey());
-        }
-        if (profile != null) {
-            appendQueryProfileProperties(profile, mentioned, b);
-        }
-        trace(b.toString(),false,4);
-    }
-
-    private Map<String, String> requestProperties() {
-        return httpRequest.propertyMap();
-    }
-
-    private void appendQueryProfileProperties(CompiledQueryProfile profile, Set<String> mentioned, StringBuilder b) {
-        for (var property : profile.listValuesWithSources(CompoundName.empty, requestProperties(), properties()).entrySet()) {
-            if ( ! mentioned.contains(property.getKey()))
-                b.append(property.getKey()).append(": ").append(property.getValue()).append("\n");
-        }
-    }
-
-    /**
      * Validates this query
      *
      * @return the reason if it is invalid, null if it is valid
@@ -602,8 +546,12 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
     /**
      * Sets the context level of this query, 0 means no tracing
      * Higher numbers means increasingly more tracing
+     *
+     * @deprecated use getTrace().setLevel(level)
      */
-    public void setTraceLevel(int traceLevel) { this.traceLevel = traceLevel; }
+    @Deprecated // TODO: Remove on Vespa 9
+    public void setTraceLevel(int traceLevel) { trace.setLevel(traceLevel); }
+
     /**
      * Sets the explain level of this query, 0 means no tracing
      * Higher numbers means increasingly more explaining
@@ -613,8 +561,11 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
     /**
      * Returns the context level of this query, 0 means no tracing
      * Higher numbers means increasingly more tracing
+     *
+     * @deprecated use getTrace().setLevel(level)
      */
-    public int getTraceLevel() { return traceLevel; }
+    @Deprecated // TODO: Remove on Vespa 9
+    public int getTraceLevel() { return trace.getLevel(); }
 
     /**
      * Returns the explain level of this query, 0 means no tracing
@@ -625,9 +576,11 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
     /**
      * Returns the context level of this query, 0 means no tracing
      * Higher numbers means increasingly more tracing
+     *
+     * @deprecated use getTrace().isTraceable(level)
      */
-    public final boolean isTraceable(int level) { return traceLevel >= level; }
-
+    @Deprecated // TODO: Remove on Vespa 9
+    public final boolean isTraceable(int level) { return trace.isTraceable(level); }
 
     /** Returns whether this query should never be served from a cache. Default is false */
     public boolean getNoCache() { return noCache; }
@@ -711,65 +664,24 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
         return model.getQueryTree().encode(buffer);
     }
 
-    /**
-     * Adds a context message to this query and to the info log,
-     * if the context level of the query is sufficiently high.
-     * The context information will be carried over to the result at creation.
-     * The message parameter will be included <i>with</i> XML escaping.
-     *
-     * @param message      the message to add
-     * @param traceLevel   the context level of the message, this method will do nothing
-     *                     if the traceLevel of the query is lower than this value
-     */
+    /** Calls getTrace().trace(message, traceLevel). */
     public void trace(String message, int traceLevel) {
-        trace(message, false, traceLevel);
+        trace.trace(message, traceLevel);
     }
 
+    /** Calls getTrace().trace(message, traceLevel). */
     public void trace(Object message, int traceLevel) {
-        if ( ! isTraceable(traceLevel)) return;
-        getContext(true).trace(message, 0);
+        trace.trace(message, traceLevel);
     }
 
-    /**
-     * Adds a trace message to this query
-     * if the trace level of the query is sufficiently high.
-     *
-     * @param message      the message to add
-     * @param includeQuery true to append the query root stringValue at the end of the message
-     * @param traceLevel   the context level of the message, this method will do nothing
-     *                     if the traceLevel of the query is lower than this value
-     */
+    /** Calls getTrace().trace(message, includeQuery, traceLevel). */
     public void trace(String message, boolean includeQuery, int traceLevel) {
-        if ( ! isTraceable(traceLevel)) return;
-
-        if (includeQuery)
-            message += ": [" + queryTreeText() + "]";
-
-        log.log(Level.FINE,message);
-
-        // Pass 0 as traceLevel as the trace level check is already done above,
-        // and it is not propagated to trace until execution has started
-        // (it is done in the execution.search method)
-        getContext(true).trace(message, 0);
+        trace.trace(message, includeQuery, traceLevel);
     }
 
-    /**
-     * Adds a trace message to this query
-     * if the trace level of the query is sufficiently high.
-     *
-     * @param includeQuery true to append the query root stringValue at the end of the message
-     * @param traceLevel   the context level of the message, this method will do nothing
-     *                     if the traceLevel of the query is lower than this value
-     * @param messages     the messages whose toStrings will be concatenated into the trace message.
-     *                     Concatenation will only happen if the trace level is sufficiently high.
-     */
+    /** Calls getTrace().trace(message, traceLevel, messages). */
     public void trace(boolean includeQuery, int traceLevel, Object... messages) {
-        if ( ! isTraceable(traceLevel)) return;
-
-        StringBuilder concatenated = new StringBuilder();
-        for (Object message : messages)
-            concatenated.append(message);
-        trace(concatenated.toString(), includeQuery, traceLevel);
+        trace.trace(includeQuery, traceLevel, messages);
     }
 
     /**
@@ -810,17 +722,6 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
         query.context = context;
     }
 
-    private String queryTreeText() {
-        QueryTree root = getModel().getQueryTree();
-
-        if (getTraceLevel() < 2)
-            return root.toString();
-        if (getTraceLevel() < 6)
-            return yqlRepresentation();
-        else
-            return "\n" + yqlRepresentation() + "\n" + new TextualQueryRepresentation(root.getRoot()) + "\n";
-    }
-
     /**
      * Serialize this query as YQL+. This method will never throw exceptions,
      * but instead return a human readable error message if a problem occurred while
@@ -1000,6 +901,7 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
         clone.model = model.cloneFor(clone);
         clone.select = select.cloneFor(clone);
         clone.ranking = ranking.cloneFor(clone);
+        clone.trace = trace.cloneFor(clone);
         clone.presentation = (Presentation) presentation.clone();
         clone.context = getContext(true).cloneFor(clone);
 
@@ -1029,6 +931,9 @@ public class Query extends com.yahoo.processing.Request implements Cloneable {
     /** Returns the query representation model to be used for this query, never null */
     public Model getModel() { return model; }
 
+    /** Returns the trace settings and facade API. */
+    public Trace getTrace() { return trace; }
+
     /**
      * Return the HTTP request which caused this query. This will never be null
      * when running with queries from the network.