diff options
Diffstat (limited to 'container-search/src/main/java/com/yahoo/search')
17 files changed, 344 insertions, 211 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 dc731669a48..48885e4b3da 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,12 +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; - // The timeout to be used when dumping rank features private static final long dumpTimeout = (6 * 60 * 1000); // 6 minutes private static final long defaultTimeout = 500; @@ -181,12 +175,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 +185,18 @@ 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"); + + /** @deprecated use Trace.EXPLAIN_LEVEL */ + @Deprecated // TODO: Remove on Vespa 9 + public static final CompoundName EXPLAIN_LEVEL = new CompoundName("explainLevel"); private static final QueryProfileType argumentType; static { @@ -213,8 +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")); argumentType.addField(new FieldDescription(TIMEOUT.toString(), "string", "timeout")); @@ -225,6 +219,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 +255,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 +399,7 @@ public class Query extends com.yahoo.processing.Request implements Cloneable { } properties().setParentQuery(this); - traceProperties(); + trace.traceProperties(); } public Query(Query query) { @@ -478,59 +474,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 @@ -599,35 +542,30 @@ public class Query extends com.yahoo.processing.Request implements Cloneable { */ public void resetTimeout() { this.startTime = System.currentTimeMillis(); } - /** - * Sets the context level of this query, 0 means no tracing - * Higher numbers means increasingly more tracing - */ - public void setTraceLevel(int traceLevel) { this.traceLevel = traceLevel; } - /** - * Sets the explain level of this query, 0 means no tracing - * Higher numbers means increasingly more explaining - */ - public void setExplainLevel(int explainLevel) { this.explainLevel = explainLevel; } + /** @deprecated use getTrace().setLevel(level) */ + @Deprecated // TODO: Remove on Vespa 9 + public void setTraceLevel(int traceLevel) { trace.setLevel(traceLevel); } - /** - * Returns the context level of this query, 0 means no tracing - * Higher numbers means increasingly more tracing - */ - public int getTraceLevel() { return traceLevel; } + /** @deprecated use getTrace().setExplainLevel(level) */ + @Deprecated // TODO: Remove on Vespa 9 + public void setExplainLevel(int explainLevel) { trace.setExplainLevel(explainLevel); } - /** - * Returns the explain level of this query, 0 means no tracing - * Higher numbers means increasingly more explaining - */ - public int getExplainLevel() { return explainLevel; } + /** @deprecated use getTrace().setLevel(level) */ + @Deprecated // TODO: Remove on Vespa 9 + public int getTraceLevel() { return trace.getLevel(); } + + /** @deprecated use getTrace().getExplainLevel(level) */ + @Deprecated // TODO: Remove on Vespa 9 + public int getExplainLevel() { return getTrace().getExplainLevel(); } /** * 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 +649,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); } /** @@ -780,47 +677,27 @@ public class Query extends com.yahoo.processing.Request implements Cloneable { * by an IllegalStateException. In other words, intended use is create the * new query, and attach the context to the invoking query as soon as the new * query is properly initialized. - * * <p> * This method will always set the argument query's context level to the context * level of this query. * - * @param query - * The query which should be traced as a part of this query. - * @throws IllegalStateException - * If the query given as argument already has context - * information. + * @param query the query which should be traced as a part of this query + * @throws IllegalStateException if the query given as argument already has context information */ public void attachContext(Query query) throws IllegalStateException { - query.setTraceLevel(getTraceLevel()); - query.setExplainLevel(getExplainLevel()); - if (context == null) { - // Nothing to attach to. This is about the same as - // getTraceLevel() == 0, - // but is a direct test of what will make the function superfluous. - return; - } + query.getTrace().setLevel(getTrace().getLevel()); + query.getTrace().setExplainLevel(getTrace().getExplainLevel()); + if (context == null) return; if (query.getContext(false) != null) { // If we added the other query's context info as a subnode in this // query's context tree, we would have to check for loops in the // context graph. If we simply created a new node without checking, // we might silently overwrite useful information. - throw new IllegalStateException("Query to attach already has context information stored."); + throw new IllegalStateException("Query to attach already has context information stored"); } 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 +877,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); @@ -1008,8 +886,6 @@ public class Query extends com.yahoo.processing.Request implements Cloneable { assert (clone.properties().getParentQuery() == clone); clone.setTimeout(getTimeout()); - clone.setTraceLevel(getTraceLevel()); - clone.setExplainLevel(getExplainLevel()); clone.setHits(getHits()); clone.setOffset(getOffset()); clone.setNoCache(getNoCache()); @@ -1029,6 +905,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. diff --git a/container-search/src/main/java/com/yahoo/search/Result.java b/container-search/src/main/java/com/yahoo/search/Result.java index b31a4fb6e24..1fd69f15012 100644 --- a/container-search/src/main/java/com/yahoo/search/Result.java +++ b/container-search/src/main/java/com/yahoo/search/Result.java @@ -245,7 +245,7 @@ public final class Result extends com.yahoo.processing.Response implements Clone * @param name the name of the searcher instance returning this result */ public void trace(String name) { - if (hits().getQuery().getTraceLevel() < 5) { + if (hits().getQuery().getTrace().getLevel() < 5) { return; } StringBuilder hitBuffer = new StringBuilder(name); diff --git a/container-search/src/main/java/com/yahoo/search/Searcher.java b/container-search/src/main/java/com/yahoo/search/Searcher.java index 473adfa17db..63dba2864f7 100644 --- a/container-search/src/main/java/com/yahoo/search/Searcher.java +++ b/container-search/src/main/java/com/yahoo/search/Searcher.java @@ -163,7 +163,7 @@ public abstract class Searcher extends Processor { } else { int fillRejectTraceAt = 3; - if (result.getQuery().getTraceLevel() >= fillRejectTraceAt) + if (result.getQuery().getTrace().getLevel() >= fillRejectTraceAt) result.getQuery().trace("Ignoring fill(" + summaryClass + "): " + ( result.hits().getFilled() == null ? "Hits are unfillable" : "Hits already filled" ) + ": result.hits().getFilled()=" + result.hits().getFilled(), fillRejectTraceAt); diff --git a/container-search/src/main/java/com/yahoo/search/cluster/ClusterSearcher.java b/container-search/src/main/java/com/yahoo/search/cluster/ClusterSearcher.java index 71758666b99..4af6757db8c 100644 --- a/container-search/src/main/java/com/yahoo/search/cluster/ClusterSearcher.java +++ b/container-search/src/main/java/com/yahoo/search/cluster/ClusterSearcher.java @@ -162,7 +162,7 @@ public abstract class ClusterSearcher<T> extends PingableSearcher implements Nod if (timedOut(query)) return new Result(query, ErrorMessage.createTimeout("No time left for searching")); - if (query.getTraceLevel() >= 8) + if (query.getTrace().getLevel() >= 8) query.trace("Trying " + connection, false, 8); result = robustSearch(query, execution, connection); @@ -170,7 +170,7 @@ public abstract class ClusterSearcher<T> extends PingableSearcher implements Nod if ( ! shouldRetry(query, result)) return result; - if (query.getTraceLevel() >= 6) + if (query.getTrace().getLevel() >= 6) query.trace("Error from connection " + connection + " : " + result.hits().getError(), false, 6); if (result.hits().getError().getCode() == Error.TIMEOUT.code) diff --git a/container-search/src/main/java/com/yahoo/search/dispatch/rpc/ProtobufSerialization.java b/container-search/src/main/java/com/yahoo/search/dispatch/rpc/ProtobufSerialization.java index 82c570a9975..8b2457606ab 100644 --- a/container-search/src/main/java/com/yahoo/search/dispatch/rpc/ProtobufSerialization.java +++ b/container-search/src/main/java/com/yahoo/search/dispatch/rpc/ProtobufSerialization.java @@ -89,12 +89,12 @@ public class ProtobufSerialization { } public static int getTraceLevelForBackend(Query query) { - int traceLevel = query.getTraceLevel(); + int traceLevel = query.getTrace().getLevel(); if (query.getModel().getExecution().trace().getForceTimestamps()) { traceLevel = Math.max(traceLevel, 5); // Backend produces timing information on level 4 and 5 } - if (query.getExplainLevel() > 0) { - traceLevel = Math.max(traceLevel, query.getExplainLevel() + 5); + if (query.getTrace().getExplainLevel() > 0) { + traceLevel = Math.max(traceLevel, query.getTrace().getExplainLevel() + 5); } return traceLevel; } @@ -157,7 +157,7 @@ public class ProtobufSerialization { if (includeQueryData) { mergeQueryDataToDocsumRequest(query, builder); } - if (query.getTraceLevel() >= 3) { + if (query.getTrace().getLevel() >= 3) { query.trace((includeQueryData ? "ProtoBuf: Resending " : "Not resending ") + "query during document summary fetching", 3); } @@ -250,7 +250,7 @@ public class ProtobufSerialization { if ( ! slimeTrace.isEmpty()) { var traces = new Value.ArrayValue(); traces.add(new SlimeAdapter(BinaryFormat.decode(slimeTrace.toByteArray()).get())); - query.trace(traces, query.getTraceLevel()); + query.trace(traces, query.getTrace().getLevel()); } return result; } diff --git a/container-search/src/main/java/com/yahoo/search/federation/FederationSearcher.java b/container-search/src/main/java/com/yahoo/search/federation/FederationSearcher.java index adf03340c6c..21b4d1d538f 100644 --- a/container-search/src/main/java/com/yahoo/search/federation/FederationSearcher.java +++ b/container-search/src/main/java/com/yahoo/search/federation/FederationSearcher.java @@ -487,7 +487,7 @@ public class FederationSearcher extends ForkingSearcher { private void traceTargets(Query query, Collection<Target> targets) { int traceFederationLevel = 2; - if ( ! query.isTraceable(traceFederationLevel)) return; + if ( ! query.getTrace().isTraceable(traceFederationLevel)) return; query.trace("Federating to " + targets, traceFederationLevel); } @@ -537,7 +537,7 @@ public class FederationSearcher extends ForkingSearcher { } } - if (query.getTraceLevel()>=4) + if (query.getTrace().getLevel()>=4) query.trace("Got " + group.getConcreteSize() + " hits from " + group.getId(),false, 4); mergedResults.hits().add(group); } diff --git a/container-search/src/main/java/com/yahoo/search/grouping/vespa/GroupingExecutor.java b/container-search/src/main/java/com/yahoo/search/grouping/vespa/GroupingExecutor.java index 694aa76e5f8..2ba33f60ea1 100644 --- a/container-search/src/main/java/com/yahoo/search/grouping/vespa/GroupingExecutor.java +++ b/container-search/src/main/java/com/yahoo/search/grouping/vespa/GroupingExecutor.java @@ -219,7 +219,7 @@ public class GroupingExecutor extends Searcher { if (lastPass > 0) { baseRoot = origRoot.clone(); } - if (query.isTraceable(3) && query.getGroupingSessionCache()) { + if (query.getTrace().isTraceable(3) && query.getGroupingSessionCache()) { query.trace("Grouping in " + (lastPass + 1) + " passes. SessionId='" + query.getSessionId() + "'.", 3); } for (int pass = 0; pass <= lastPass; ++pass) { @@ -242,7 +242,7 @@ public class GroupingExecutor extends Searcher { // noinspection ConstantConditions passRoot = baseRoot.clone(); } - if (query.isTraceable(4) && query.getGroupingSessionCache()) { + if (query.getTrace().isTraceable(4) && query.getGroupingSessionCache()) { query.trace("Grouping with session cache '" + query.getGroupingSessionCache() + "' enabled for pass #" + pass + ".", 4); } if (origRoot != passRoot) { diff --git a/container-search/src/main/java/com/yahoo/search/pagetemplates/result/PageTemplatesXmlRenderer.java b/container-search/src/main/java/com/yahoo/search/pagetemplates/result/PageTemplatesXmlRenderer.java index 6d69a2cb877..98789480a1e 100644 --- a/container-search/src/main/java/com/yahoo/search/pagetemplates/result/PageTemplatesXmlRenderer.java +++ b/container-search/src/main/java/com/yahoo/search/pagetemplates/result/PageTemplatesXmlRenderer.java @@ -122,7 +122,7 @@ public class PageTemplatesXmlRenderer extends AsynchronousSectionedRenderer<Resu } private void queryContext(XMLWriter writer, Query owner) { - if (owner.getTraceLevel()!=0) { + if (owner.getTrace().getLevel()!=0) { XMLWriter xmlWriter=XMLWriter.from(writer); xmlWriter.openTag("meta").attribute("type", QueryContext.ID); TraceNode traceRoot = owner.getModel().getExecution().trace().traceNode().root(); diff --git a/container-search/src/main/java/com/yahoo/search/query/Model.java b/container-search/src/main/java/com/yahoo/search/query/Model.java index dbaab3045bf..63fc386963a 100644 --- a/container-search/src/main/java/com/yahoo/search/query/Model.java +++ b/container-search/src/main/java/com/yahoo/search/query/Model.java @@ -248,7 +248,7 @@ public class Model implements Cloneable { try { Parser parser = ParserFactory.newInstance(type, ParserEnvironment.fromExecutionContext(execution.context())); queryTree = parser.parse(Parsable.fromQueryModel(this)); - if (parent.getTraceLevel() >= 2) + if (parent.getTrace().getLevel() >= 2) parent.trace("Query parsed to: " + parent.yqlRepresentation(), 2); } catch (IllegalArgumentException e) { diff --git a/container-search/src/main/java/com/yahoo/search/query/Trace.java b/container-search/src/main/java/com/yahoo/search/query/Trace.java new file mode 100644 index 00000000000..9f056b14c21 --- /dev/null +++ b/container-search/src/main/java/com/yahoo/search/query/Trace.java @@ -0,0 +1,242 @@ +// Copyright Yahoo. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. +package com.yahoo.search.query; + +import com.yahoo.api.annotations.Beta; +import com.yahoo.prelude.query.textualrepresentation.TextualQueryRepresentation; +import com.yahoo.processing.request.CompoundName; +import com.yahoo.search.Query; +import com.yahoo.search.query.profile.QueryProfileProperties; +import com.yahoo.search.query.profile.compiled.CompiledQueryProfile; +import com.yahoo.search.query.profile.types.FieldDescription; +import com.yahoo.search.query.profile.types.QueryProfileType; + +import java.util.HashSet; +import java.util.Map; +import java.util.Objects; +import java.util.Set; +import java.util.logging.Level; +import java.util.logging.Logger; + +/** + * Trace settings and methods for tracing a query. + * The actual trace is a tree structure stored in the query execution. + * + * @author bratseth + */ +@Beta +public class Trace implements Cloneable { + + private static final Logger log = Logger.getLogger(Trace.class.getName()); + + /** The type representing the property arguments consumed by this */ + private static final QueryProfileType argumentType; + + public static final String TRACE = "trace"; + public static final String LEVEL = "level"; + public static final String EXPLAIN_LEVEL = "explainLevel"; + public static final String TIMESTAMPS = "timestamps"; + public static final String QUERY = "query"; + + static { + argumentType = new QueryProfileType(TRACE); + argumentType.setStrict(true); + argumentType.setBuiltin(true); + argumentType.addField(new FieldDescription(LEVEL, "integer", "tracelevel traceLevel")); + argumentType.addField(new FieldDescription(EXPLAIN_LEVEL, "integer", "explainlevel explainLevel")); + argumentType.addField(new FieldDescription(TIMESTAMPS, "boolean")); + argumentType.addField(new FieldDescription(QUERY, "boolean")); + argumentType.freeze(); + } + + public static QueryProfileType getArgumentType() { return argumentType; } + + private Query parent; + + private int level = 0; + private int explainLevel = 0; + private boolean timestamps = false; + private boolean query = true; + + public Trace(Query parent) { + this.parent = Objects.requireNonNull(parent); + } + + /** Returns the level of detail we'll be tracing at in this query. The default level is 0; no tracing. */ + public int getLevel() { return level; } + public void setLevel(int level) { this.level = level; } + public boolean isTraceable(int level) { return level <= this.level; } + + /** Sets the explain level of this query, 0 means no tracing. Higher numbers means increasingly more explaining. */ + public void setExplainLevel(int explainLevel) { this.explainLevel = explainLevel; } + public int getExplainLevel() { return explainLevel; } + + /** Returns whether trace entries should have a timestamp. Default is false. */ + public boolean getTimestamps() { return timestamps; } + public void setTimestamps(boolean timestamps) { this.timestamps = timestamps; } + + /** Returns whether any trace entries should include the query. Default is true. */ + public boolean getQuery() { return query; } + public void setQuery(boolean query) { this.query = query; } + + /** + * 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 + */ + public void trace(String message, int traceLevel) { + trace(message, false, traceLevel); + } + + public void trace(Object message, int traceLevel) { + if ( ! isTraceable(traceLevel)) return; + parent.getContext(true).trace(message, 0); + } + + /** + * 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 + */ + public void trace(String message, boolean includeQuery, int traceLevel) { + if ( ! isTraceable(traceLevel)) return; + + if (includeQuery && query) + 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) + parent.getContext(true).trace(message, 0); + } + + /** + * 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. + */ + 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); + } + + /** + * 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 + */ + public void traceProperties() { + if (level == 0) return; + CompiledQueryProfile profile = null; + QueryProfileProperties profileProperties = parent.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 (level < 4) return; + StringBuilder b = new StringBuilder("Resolved properties:\n"); + Set<String> mentioned = new HashSet<>(); + for (Map.Entry<String,String> requestProperty : requestProperties().entrySet() ) { + Object resolvedValue = parent.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 void appendQueryProfileProperties(CompiledQueryProfile profile, Set<String> mentioned, StringBuilder b) { + for (var property : profile.listValuesWithSources(CompoundName.empty, requestProperties(), parent.properties()).entrySet()) { + if ( ! mentioned.contains(property.getKey())) + b.append(property.getKey()).append(": ").append(property.getValue()).append("\n"); + } + } + + private Map<String, String> requestProperties() { + return parent.getHttpRequest().propertyMap(); + } + + private String queryTreeText() { + QueryTree root = parent.getModel().getQueryTree(); + + if (level < 2) + return root.toString(); + if (level < 6) + return parent.yqlRepresentation(); + else + return "\n" + parent.yqlRepresentation() + "\n" + new TextualQueryRepresentation(root.getRoot()) + "\n"; + } + + public Trace cloneFor(Query parent) { + Trace trace = this.clone(); + trace.parent = parent; + return trace; + } + + @Override + public boolean equals(Object o) { + if (o == this ) return true; + if ( ! (o instanceof Trace)) return false; + Trace other = (Trace)o; + if (other.level != this.level) return false; + if (other.explainLevel != this.explainLevel) return false; + if (other.timestamps != this.timestamps) return false; + if (other.query != this.query) return false; + return true; + } + + @Override + public int hashCode() { return Objects.hash(level, explainLevel, timestamps, query); } + + @Override + public Trace clone() { + try { + return (Trace)super.clone(); + } + catch (CloneNotSupportedException e) { + throw new RuntimeException(e); + } + } + + @Override + public String toString() { + return "trace [level: " + level + ", explainLevel: " + explainLevel + ", timestamps: " + timestamps + ", query: " + query + "]"; + } + +} diff --git a/container-search/src/main/java/com/yahoo/search/query/context/QueryContext.java b/container-search/src/main/java/com/yahoo/search/query/context/QueryContext.java index 38f76c6ca49..c0ca5ac4731 100644 --- a/container-search/src/main/java/com/yahoo/search/query/context/QueryContext.java +++ b/container-search/src/main/java/com/yahoo/search/query/context/QueryContext.java @@ -87,7 +87,7 @@ public class QueryContext implements Cloneable { } public boolean render(Writer writer) throws java.io.IOException { - if (owner.getTraceLevel()!=0) { + if (owner.getTrace().getLevel()!=0) { XMLWriter xmlWriter=XMLWriter.from(writer); xmlWriter.openTag("meta").attribute("type",ID); TraceNode traceRoot=owner.getModel().getExecution().trace().traceNode().root(); diff --git a/container-search/src/main/java/com/yahoo/search/query/profile/QueryProfile.java b/container-search/src/main/java/com/yahoo/search/query/profile/QueryProfile.java index 989f12172b3..e3ab49f0e32 100644 --- a/container-search/src/main/java/com/yahoo/search/query/profile/QueryProfile.java +++ b/container-search/src/main/java/com/yahoo/search/query/profile/QueryProfile.java @@ -344,7 +344,7 @@ public class QueryProfile extends FreezableSimpleComponent implements Cloneable * a primitive value, a substitutable string, a query profile, or null if not found. */ public final Object lookup(String name, Map<String, String> context) { - return lookup(new CompoundName(name),true,DimensionBinding.createFrom(getDimensions(),context)); + return lookup(new CompoundName(name), true, DimensionBinding.createFrom(getDimensions(),context)); } /** Sets a value in this or any nested profile using null as context */ @@ -733,7 +733,7 @@ public class QueryProfile extends FreezableSimpleComponent implements Cloneable // ----------------- Private ---------------------------------------------------------------------------------- - private Boolean isDeclaredOverridable(CompoundName name,DimensionBinding dimensionBinding) { + private Boolean isDeclaredOverridable(CompoundName name, DimensionBinding dimensionBinding) { QueryProfile parent = lookupParentExact(name, true, dimensionBinding); if (parent.overridable == null) return null; return parent.overridable.get(name.last()); @@ -743,15 +743,15 @@ public class QueryProfile extends FreezableSimpleComponent implements Cloneable * Sets the overridability of a field in this profile, * this overrides the corresponding setting in the type (if any) */ - private void setOverridable(CompoundName fieldName, boolean overridable, DimensionBinding dimensionBinding) { - QueryProfile parent = lookupParentExact(fieldName, true, dimensionBinding); + private void setOverridable(CompoundName name, boolean overridable, DimensionBinding dimensionBinding) { + QueryProfile parent = lookupParentExact(name, true, dimensionBinding); if (dimensionBinding.isNull()) { if (parent.overridable == null) parent.overridable = new HashMap<>(); - parent.overridable.put(fieldName.last(), overridable); + parent.overridable.put(name.last(), overridable); } else { - variants.setOverridable(fieldName.last(), overridable, dimensionBinding.getValues()); + variants.setOverridable(name.last(), overridable, dimensionBinding.getValues()); } } diff --git a/container-search/src/main/java/com/yahoo/search/query/properties/QueryProperties.java b/container-search/src/main/java/com/yahoo/search/query/properties/QueryProperties.java index 4cced8d7923..f6e158cf04a 100644 --- a/container-search/src/main/java/com/yahoo/search/query/properties/QueryProperties.java +++ b/container-search/src/main/java/com/yahoo/search/query/properties/QueryProperties.java @@ -11,6 +11,7 @@ import com.yahoo.search.query.Presentation; import com.yahoo.search.query.Properties; import com.yahoo.search.query.Ranking; import com.yahoo.search.query.Select; +import com.yahoo.search.query.Trace; import com.yahoo.search.query.profile.compiled.CompiledQueryProfileRegistry; import com.yahoo.search.query.profile.types.ConversionContext; import com.yahoo.search.query.profile.types.FieldDescription; @@ -132,11 +133,16 @@ public class QueryProperties extends Properties { } else if (key.size() == 3 && key.get(1).equals(Presentation.FORMAT)) { if (key.last().equals(Presentation.TENSORS)) return query.getPresentation().getTensorShortForm(); } - } else if (key.size() == 1) { + } + else if (key.size() == 2 && key.first().equals(Trace.TRACE)) { + if (key.last().equals(Trace.LEVEL)) return query.getTrace().getLevel(); + if (key.last().equals(Trace.EXPLAIN_LEVEL)) return query.getTrace().getExplainLevel(); + if (key.last().equals(Trace.TIMESTAMPS)) return query.getTrace().getTimestamps(); + if (key.last().equals(Trace.QUERY)) return query.getTrace().getQuery(); + } + else if (key.size() == 1) { if (key.equals(Query.HITS)) return query.getHits(); if (key.equals(Query.OFFSET)) return query.getOffset(); - if (key.equals(Query.TRACE_LEVEL)) return query.getTraceLevel(); - if (key.equals(Query.EXPLAIN_LEVEL)) return query.getExplainLevel(); if (key.equals(Query.TIMEOUT)) return query.getTimeout(); if (key.equals(Query.NO_CACHE)) return query.getNoCache(); if (key.equals(Query.GROUPING_SESSION_CACHE)) return query.getGroupingSessionCache(); @@ -301,6 +307,16 @@ public class QueryProperties extends Properties { else throwIllegalParameter(key.last(), Presentation.PRESENTATION); } + else if (key.size() == 2 && key.first().equals(Trace.TRACE)) { + if (key.last().equals(Trace.LEVEL)) + query.getTrace().setLevel(asInteger(value, 0)); + if (key.last().equals(Trace.EXPLAIN_LEVEL)) + query.getTrace().setExplainLevel(asInteger(value, 0)); + if (key.last().equals(Trace.TIMESTAMPS)) + query.getTrace().setTimestamps(asBoolean(value, false)); + if (key.last().equals(Trace.QUERY)) + query.getTrace().setQuery(asBoolean(value, true)); + } else if (key.first().equals(Select.SELECT)) { if (key.size() == 1) { query.getSelect().setGroupingExpressionString(asString(value, "")); @@ -322,10 +338,6 @@ public class QueryProperties extends Properties { query.setHits(asInteger(value,10)); else if (key.equals(Query.OFFSET)) query.setOffset(asInteger(value,0)); - else if (key.equals(Query.TRACE_LEVEL)) - query.setTraceLevel(asInteger(value,0)); - else if (key.equals(Query.EXPLAIN_LEVEL)) - query.setExplainLevel(asInteger(value,0)); else if (key.equals(Query.TIMEOUT)) query.setTimeout(value.toString()); else if (key.equals(Query.NO_CACHE)) diff --git a/container-search/src/main/java/com/yahoo/search/querytransform/BooleanSearcher.java b/container-search/src/main/java/com/yahoo/search/querytransform/BooleanSearcher.java index d3bb1e7a81d..f43be20e0ac 100644 --- a/container-search/src/main/java/com/yahoo/search/querytransform/BooleanSearcher.java +++ b/container-search/src/main/java/com/yahoo/search/querytransform/BooleanSearcher.java @@ -39,7 +39,7 @@ public class BooleanSearcher extends Searcher { if (fieldName != null) { return search(query, execution, fieldName); } else { - if (query.isTraceable(5)) { + if (query.getTrace().isTraceable(5)) { query.trace("BooleanSearcher: Nothing added to query", false, 5); } } @@ -49,7 +49,7 @@ public class BooleanSearcher extends Searcher { private Result search(Query query, Execution execution, String fieldName) { String attributes = query.properties().getString(ATTRIBUTES); String rangeAttributes = query.properties().getString(RANGE_ATTRIBUTES); - if (query.isTraceable(5)) { + if (query.getTrace().isTraceable(5)) { query.trace("BooleanSearcher: fieldName(" + fieldName + "), attributes(" + attributes + "), rangeAttributes(" + rangeAttributes + ")", false, 5); } @@ -57,7 +57,7 @@ public class BooleanSearcher extends Searcher { if (attributes != null || rangeAttributes != null) { try { addPredicateTerm(query, fieldName, attributes, rangeAttributes); - if (query.isTraceable(4)) { + if (query.getTrace().isTraceable(4)) { query.trace("BooleanSearcher: Added boolean operator", true, 4); } } catch (TokenMgrException e) { @@ -68,7 +68,7 @@ public class BooleanSearcher extends Searcher { } } else { - if (query.isTraceable(5)) { + if (query.getTrace().isTraceable(5)) { query.trace("BooleanSearcher: Nothing added to query", false, 5); } } diff --git a/container-search/src/main/java/com/yahoo/search/rendering/JsonRenderer.java b/container-search/src/main/java/com/yahoo/search/rendering/JsonRenderer.java index 250e66ca9fb..58353cc5907 100644 --- a/container-search/src/main/java/com/yahoo/search/rendering/JsonRenderer.java +++ b/container-search/src/main/java/com/yahoo/search/rendering/JsonRenderer.java @@ -224,7 +224,7 @@ public class JsonRenderer extends AsynchronousSectionedRenderer<Result> { protected void renderTrace(Trace trace) throws IOException { if (!trace.traceNode().children().iterator().hasNext()) return; - if (getResult().getQuery().getTraceLevel() == 0) return; + if (getResult().getQuery().getTrace().getLevel() == 0) return; try { long basetime = trace.traceNode().timestamp(); diff --git a/container-search/src/main/java/com/yahoo/search/rendering/XmlRenderer.java b/container-search/src/main/java/com/yahoo/search/rendering/XmlRenderer.java index f93c70c0199..53e59d9deea 100644 --- a/container-search/src/main/java/com/yahoo/search/rendering/XmlRenderer.java +++ b/container-search/src/main/java/com/yahoo/search/rendering/XmlRenderer.java @@ -160,7 +160,7 @@ public final class XmlRenderer extends AsynchronousSectionedRenderer<Result> { @SuppressWarnings("UnusedParameters") public void queryContext(XMLWriter writer, QueryContext queryContext, Query owner) throws IOException { - if (owner.getTraceLevel()!=0) { + if (owner.getTrace().getLevel()!=0) { XMLWriter xmlWriter=XMLWriter.from(writer); xmlWriter.openTag("meta").attribute("type", QueryContext.ID); TraceNode traceRoot = owner.getModel().getExecution().trace().traceNode().root(); diff --git a/container-search/src/main/java/com/yahoo/search/searchchain/Execution.java b/container-search/src/main/java/com/yahoo/search/searchchain/Execution.java index 02537e63a6b..988021a6da0 100644 --- a/container-search/src/main/java/com/yahoo/search/searchchain/Execution.java +++ b/container-search/src/main/java/com/yahoo/search/searchchain/Execution.java @@ -494,7 +494,7 @@ public class Execution extends com.yahoo.processing.execution.Execution { // Transfer state between query and execution as the execution constructors does not do that completely query.getModel().setExecution(this); - trace().setTraceLevel(query.getTraceLevel()); + trace().setTraceLevel(query.getTrace().getLevel()); return (Result)super.process(query); } @@ -504,7 +504,7 @@ public class Execution extends com.yahoo.processing.execution.Execution { super.onInvoking(request,processor); final int traceDependencies = 6; Query query = (Query) request; - if (query.getTraceLevel() >= traceDependencies) { + if (query.getTrace().getLevel() >= traceDependencies) { query.trace(processor.getId() + " " + processor.getDependencies(), traceDependencies); } } |