Merge pull request #23097 from vespa-engine/bratseth/trace

Bratseth/trace 

8 files changed, 123 insertions, 100 deletions

diff --git a/container-search/src/test/java/com/yahoo/prelude/querytransform/test/NormalizingSearcherTestCase.java b/container-search/src/test/java/com/yahoo/prelude/querytransform/test/NormalizingSearcherTestCase.java
index 0694c1a7e55..7ab50118c6d 100644
--- a/container-search/src/test/java/com/yahoo/prelude/querytransform/test/NormalizingSearcherTestCase.java
+++ b/container-search/src/test/java/com/yahoo/prelude/querytransform/test/NormalizingSearcherTestCase.java
@@ -84,7 +84,7 @@ public class NormalizingSearcherTestCase {
     @Test
     public void testPhraseQuery() {
         Query query = new Query("/search?query=" + enc("\"b\u00e9yonc\u00e8 beyonc\u00e9\"") + "&search=cluster1&restrict=type1");
-        query.setTraceLevel(2);
+        query.getTrace().setLevel(2);
         createExecution().search(query);
         assertEquals("WEAKAND(100) \"beyonce beyonce\"", query.getModel().getQueryTree().getRoot().toString());
     }
diff --git a/container-search/src/test/java/com/yahoo/prelude/searcher/test/JSONDebugSearcherTestCase.java b/container-search/src/test/java/com/yahoo/prelude/searcher/test/JSONDebugSearcherTestCase.java
index 2841ce5521a..6a230da4950 100644
--- a/container-search/src/test/java/com/yahoo/prelude/searcher/test/JSONDebugSearcherTestCase.java
+++ b/container-search/src/test/java/com/yahoo/prelude/searcher/test/JSONDebugSearcherTestCase.java
@@ -14,36 +14,35 @@ import com.yahoo.search.searchchain.Execution;
 import com.yahoo.search.searchchain.testutil.DocumentSourceSearcher;
 import com.yahoo.yolean.trace.TraceNode;
 import com.yahoo.yolean.trace.TraceVisitor;
-import org.junit.After;
-import org.junit.Before;
 import org.junit.Test;
 
-import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertFalse;
+import static org.junit.Assert.assertTrue;
 
 /**
  * Visit the trace and check JSON payload is stored there when requested.
  *
- * @author <a href="mailto:steinar@yahoo-inc.com">Steinar Knutsen</a>
+ * @author Steinar Knutsen
  */
 public class JSONDebugSearcherTestCase {
 
     private static final String NODUMPJSON = "?query=1&tracelevel=6";
     private static final String DUMPJSON = "?query=1&dumpjson=jsonfield&tracelevel=6";
-    private Chain<Searcher> searchChain;
 
-    private static class LookForJson extends TraceVisitor {
-        private static final String JSON_PAYLOAD = "{1: 2}";
-        public boolean gotJson = false;
-
-        @Override
-        public void visit(TraceNode node) {
-            if (node.payload() == null || node.payload().getClass() != String.class) {
-                return;
-            }
-            if (node.payload().toString().equals(JSONDebugSearcher.JSON_FIELD + JSON_PAYLOAD)) {
-                gotJson = true;
-            }
-        }
+    @Test
+    public void test() {
+        Chain<Searcher> searchChain = makeSearchChain("{1: 2}", new JSONDebugSearcher());
+        Execution e = new Execution(searchChain, Execution.Context.createContextStub());
+        e.search(new Query(NODUMPJSON));
+        Trace t = e.trace();
+        LookForJson visitor = new LookForJson();
+        t.accept(visitor);
+        assertFalse(visitor.gotJson);
+        e = new Execution(searchChain, Execution.Context.createContextStub());
+        e.search(new Query(DUMPJSON));
+        t = e.trace();
+        t.accept(visitor);
+        assertTrue(visitor.gotJson);
     }
 
     private Chain<Searcher> makeSearchChain(String content, Searcher dumper) {
@@ -63,29 +62,20 @@ public class JSONDebugSearcherTestCase {
         docsource.addResult(q, r);
     }
 
+    private static class LookForJson extends TraceVisitor {
 
-    @Before
-    public void setUp() throws Exception {
-        searchChain = makeSearchChain("{1: 2}", new JSONDebugSearcher());
-    }
-
-    @After
-    public void tearDown() throws Exception {
-    }
+        private static final String JSON_PAYLOAD = "{1: 2}";
+        public boolean gotJson = false;
 
-    @Test
-    public final void test() {
-        Execution e = new Execution(searchChain, Execution.Context.createContextStub());
-        e.search(new Query(NODUMPJSON));
-        Trace t = e.trace();
-        LookForJson visitor = new LookForJson();
-        t.accept(visitor);
-        assertEquals(false, visitor.gotJson);
-        e = new Execution(searchChain, Execution.Context.createContextStub());
-        e.search(new Query(DUMPJSON));
-        t = e.trace();
-        t.accept(visitor);
-        assertEquals(true, visitor.gotJson);
+        @Override
+        public void visit(TraceNode node) {
+            if (node.payload() == null || node.payload().getClass() != String.class) {
+                return;
+            }
+            if (node.payload().toString().equals(JSONDebugSearcher.JSON_FIELD + JSON_PAYLOAD)) {
+                gotJson = true;
+            }
+        }
     }
 
 }
diff --git a/container-search/src/test/java/com/yahoo/search/dispatch/InterleavedSearchInvokerTest.java b/container-search/src/test/java/com/yahoo/search/dispatch/InterleavedSearchInvokerTest.java
index 347276d680d..e07d38fbf10 100644
--- a/container-search/src/test/java/com/yahoo/search/dispatch/InterleavedSearchInvokerTest.java
+++ b/container-search/src/test/java/com/yahoo/search/dispatch/InterleavedSearchInvokerTest.java
@@ -488,7 +488,7 @@ public class InterleavedSearchInvokerTest {
         public TestQuery() {
             super();
             setTimeout(5000);
-            setTraceLevel(5);
+            getTrace().setLevel(5);
         }
 
         @Override
diff --git a/container-search/src/test/java/com/yahoo/search/query/profile/config/test/XmlReadingTestCase.java b/container-search/src/test/java/com/yahoo/search/query/profile/config/test/XmlReadingTestCase.java
index b1faac2036b..62bc89c8453 100644
--- a/container-search/src/test/java/com/yahoo/search/query/profile/config/test/XmlReadingTestCase.java
+++ b/container-search/src/test/java/com/yahoo/search/query/profile/config/test/XmlReadingTestCase.java
@@ -49,80 +49,82 @@ public class XmlReadingTestCase {
 
     @Test
     public void testValid() {
-        QueryProfileRegistry registry=
+        QueryProfileRegistry registry =
                 new QueryProfileXMLReader().read("src/test/java/com/yahoo/search/query/profile/config/test/validxml");
-        CompiledQueryProfileRegistry cRegistry= registry.compile();
+        CompiledQueryProfileRegistry cRegistry = registry.compile();
 
         QueryProfileType rootType = registry.getType("rootType");
-        assertEquals(1,rootType.inherited().size());
-        assertEquals("native",rootType.inherited().get(0).getId().getName());
+        assertEquals(1, rootType.inherited().size());
+        assertEquals("native", rootType.inherited().get(0).getId().getName());
         assertTrue(rootType.isStrict());
         assertTrue(rootType.getMatchAsPath());
-        FieldDescription timeField=rootType.getField("time");
+        FieldDescription timeField = rootType.getField("time");
         assertTrue(timeField.isMandatory());
-        assertEquals("long",timeField.getType().toInstanceDescription());
-        FieldDescription userField=rootType.getField("user");
+        assertEquals("long", timeField.getType().toInstanceDescription());
+        FieldDescription userField = rootType.getField("user");
         assertFalse(userField.isMandatory());
-        assertEquals("reference to a query profile of type 'user'",userField.getType().toInstanceDescription());
+        assertEquals("reference to a query profile of type 'user'", userField.getType().toInstanceDescription());
 
-        QueryProfileType user=registry.getType("user");
-        assertEquals(0,user.inherited().size());
+        QueryProfileType user = registry.getType("user");
+        assertEquals(0, user.inherited().size());
         assertFalse(user.isStrict());
         assertFalse(user.getMatchAsPath());
         assertTrue(userField.isOverridable());
-        FieldDescription ageField=user.getField("age");
+        FieldDescription ageField = user.getField("age");
         assertTrue(ageField.isMandatory());
-        assertEquals("integer",ageField.getType().toInstanceDescription());
-        FieldDescription robotField=user.getField("robot");
+        assertEquals("integer", ageField.getType().toInstanceDescription());
+        FieldDescription robotField = user.getField("robot");
         assertFalse(robotField.isMandatory());
         assertFalse(robotField.isOverridable());
-        assertEquals("boolean",robotField.getType().toInstanceDescription());
+        assertEquals("boolean", robotField.getType().toInstanceDescription());
 
-        CompiledQueryProfile defaultProfile=cRegistry.getComponent("default");
+        CompiledQueryProfile defaultProfile = cRegistry.getComponent("default");
         assertNull(defaultProfile.getType());
-        assertEquals("20",defaultProfile.get("hits"));
+        assertEquals("20", defaultProfile.get("hits"));
         assertFalse(defaultProfile.isOverridable(new CompoundName("hits"), null));
         assertFalse(defaultProfile.isOverridable(new CompoundName("user.trusted"), null));
-        assertEquals("false",defaultProfile.get("user.trusted"));
+        assertEquals("false", defaultProfile.get("user.trusted"));
 
-        CompiledQueryProfile referencingProfile=cRegistry.getComponent("referencingModelSettings");
+        CompiledQueryProfile referencingProfile = cRegistry.getComponent("referencingModelSettings");
         assertNull(referencingProfile.getType());
-        assertEquals("some query",referencingProfile.get("model.queryString"));
-        assertEquals("aDefaultIndex",referencingProfile.get("model.defaultIndex"));
+        assertEquals("some query", referencingProfile.get("model.queryString"));
+        assertEquals("aDefaultIndex", referencingProfile.get("model.defaultIndex"));
 
         // Request parameters here should be ignored
-        HttpRequest request=HttpRequest.createTestRequest("?query=foo&user.trusted=true&default-index=title", Method.GET);
-        Query query=new Query(request, defaultProfile);
-        assertEquals("false",query.properties().get("user.trusted"));
-        assertEquals("default",query.getModel().getDefaultIndex());
-        assertEquals("default",query.properties().get("default-index"));
-
-        CompiledQueryProfile rootProfile=cRegistry.getComponent("root");
-        assertEquals("rootType",rootProfile.getType().getId().getName());
-        assertEquals(30,rootProfile.get("hits"));
-        assertEquals(3,rootProfile.get("traceLevel"));
+        HttpRequest request = HttpRequest.createTestRequest("?query=foo&user.trusted=true&default-index=title", Method.GET);
+        Query query = new Query(request, defaultProfile);
+        assertEquals("false", query.properties().get("user.trusted"));
+        assertEquals("default", query.getModel().getDefaultIndex());
+        assertEquals("default", query.properties().get("default-index"));
+
+        CompiledQueryProfile rootProfile = cRegistry.getComponent("root");
+        assertEquals("rootType", rootProfile.getType().getId().getName());
+        assertEquals(30, rootProfile.get("hits"));
+        //assertEquals(3, rootProfile.get("traceLevel"));
         assertTrue(rootProfile.isOverridable(new CompoundName("hits"), null));
+        query = new Query(request, rootProfile);
+        assertEquals(3, query.getTrace().getLevel());
 
-        QueryProfile someUser=registry.getComponent("someUser");
+        QueryProfile someUser = registry.getComponent("someUser");
         assertEquals("5",someUser.get("sub.test"));
         assertEquals(18,someUser.get("age"));
 
         // aliases
-        assertEquals(18,someUser.get("alder"));
-        assertEquals(18,someUser.get("anno"));
-        assertEquals(18,someUser.get("aLdER"));
-        assertEquals(18,someUser.get("ANNO"));
+        assertEquals(18, someUser.get("alder"));
+        assertEquals(18, someUser.get("anno"));
+        assertEquals(18, someUser.get("aLdER"));
+        assertEquals(18, someUser.get("ANNO"));
         assertNull(someUser.get("Age")); // Only aliases are case insensitive
 
         Map<String, String> context = new HashMap<>();
         context.put("x", "x1");
         assertEquals(37, someUser.get("alder", context, null));
-        assertEquals(37,someUser.get("anno", context, null));
-        assertEquals(37,someUser.get("aLdER", context, null));
-        assertEquals(37,someUser.get("ANNO", context, null));
-        assertEquals("male",someUser.get("gender", context, null));
-        assertEquals("male",someUser.get("sex", context, null));
-        assertEquals("male",someUser.get("Sex", context, null));
+        assertEquals(37, someUser.get("anno", context, null));
+        assertEquals(37, someUser.get("aLdER", context, null));
+        assertEquals(37, someUser.get("ANNO", context, null));
+        assertEquals("male", someUser.get("gender", context, null));
+        assertEquals("male", someUser.get("sex", context, null));
+        assertEquals("male", someUser.get("Sex", context, null));
         assertNull(someUser.get("Gender", context, null)); // Only aliases are case insensitive
     }
 
diff --git a/container-search/src/test/java/com/yahoo/search/query/profile/config/test/validxml/root.xml b/container-search/src/test/java/com/yahoo/search/query/profile/config/test/validxml/root.xml
index 82ff7afb186..e7a5f132aaf 100644
--- a/container-search/src/test/java/com/yahoo/search/query/profile/config/test/validxml/root.xml
+++ b/container-search/src/test/java/com/yahoo/search/query/profile/config/test/validxml/root.xml
@@ -4,6 +4,6 @@
 <query-profile id="root" type="rootType">
 
   <field name="hits">30</field>
-  <field name="traceLevel">3</field>
+  <field name="trace.level">3</field>
     
 </query-profile>
diff --git a/container-search/src/test/java/com/yahoo/search/searchchain/test/TraceTestCase.java b/container-search/src/test/java/com/yahoo/search/searchchain/test/TraceTestCase.java
index 90da5a5b746..04b1fd85872 100644
--- a/container-search/src/test/java/com/yahoo/search/searchchain/test/TraceTestCase.java
+++ b/container-search/src/test/java/com/yahoo/search/searchchain/test/TraceTestCase.java
@@ -48,11 +48,33 @@ public class TraceTestCase {
     public void testTracingOnIncorrectAPIUseParallel() {
         assertTracing(false,true);
     }
-    
+
+    @Test
+    public void testTraceWithQuery() {
+        testQueryInTrace(true, "trace.query=true");
+        testQueryInTrace(false, "trace.query=false");
+        testQueryInTrace(true, "");
+    }
+
+    private void testQueryInTrace(boolean expectQueryInTrace, String queryParameters) {
+        Query query = new Query("?query=foo&trace.level=1&" + queryParameters);
+        Chain<Searcher> chain = new Chain<>(new Tracer("tracer1", true));
+        Execution execution = new Execution(chain, Execution.Context.createContextStub());
+        Result result = execution.search(query);
+        Iterator<String> trace = collectTrace(query).iterator();
+        assertEquals("(level start)", trace.next());
+        assertEquals("  No query profile is used", trace.next());
+        assertEquals("  (level start)", trace.next());
+        if (expectQueryInTrace)
+            assertEquals("    During tracer1: 0: [WEAKAND(100) foo]", trace.next());
+        else
+            assertEquals("    During tracer1: 0", trace.next());
+    }
+
     @Test 
     public void testTraceInvocationsUnfillableHits() {
         final int traceLevel = 5;
-        Query query = new Query("?tracelevel=" + traceLevel);
+        Query query = new Query("?trace.level=" + traceLevel);
         Chain<Searcher> forkingChain = new Chain<>(new Tracer("tracer1"), 
                                                    new Tracer("tracer2"), 
                                                    new Backend("backend1", false));
@@ -118,7 +140,8 @@ public class TraceTestCase {
 
     private void assertTracing(boolean carryOverContext, boolean parallel) {
         Query query = new Query("?tracelevel=1");
-        query.trace("Before execution",1);
+        assertEquals(1, query.getTrace().getLevel());
+        query.trace("Before execution", 1);
         Chain<Searcher> forkingChain = new Chain<>(new Tracer("forker"), 
                                                    new Forker(carryOverContext, parallel, 
                                                               new Tracer("branch 1") ,
@@ -222,8 +245,8 @@ public class TraceTestCase {
 
     private static class TraceCollector extends TraceVisitor {
 
-        private List<String> trace = new ArrayList<>();
-        private StringBuilder indent = new StringBuilder();
+        private final List<String> trace = new ArrayList<>();
+        private final StringBuilder indent = new StringBuilder();
 
         @Override
         public void entering(TraceNode node) {
@@ -249,30 +272,38 @@ public class TraceTestCase {
 
     private static class Tracer extends Searcher {
 
-        private String name;
+        private final String name;
+        private final boolean traceQuery;
+
         private int counter = 0;
 
         public Tracer(String name) {
+            this(name, false);
+        }
+
+        public Tracer(String name, boolean traceQuery) {
             super(new ComponentId(name));
             this.name = name;
+            this.traceQuery = traceQuery;
         }
 
         @Override
         public Result search(Query query, Execution execution) {
-            query.trace("During " + name + ": " + (counter++),1);
+            query.trace("During " + name + ": " + (counter++), traceQuery, 1);
             return execution.search(query);
         }
+
     }
 
     private static class Forker extends Searcher {
 
-        private List<Searcher> branches;
+        private final List<Searcher> branches;
 
         /** If true, this is using the api as recommended, if false, it is not */
-        private boolean carryOverContext;
+        private final boolean carryOverContext;
 
         /** If true, simulate parallel execution by cloning the query */
-        private boolean parallel;
+        private final boolean parallel;
 
         public Forker(boolean carryOverContext, boolean parallel, Searcher ... branches) {
             this.carryOverContext = carryOverContext;
@@ -280,7 +311,6 @@ public class TraceTestCase {
             this.branches = Arrays.asList(branches);
         }
 
-        @SuppressWarnings("deprecation")
         @Override
         public Result search(Query query, Execution execution) {
             Result result = execution.search(query);
@@ -319,6 +349,7 @@ public class TraceTestCase {
             result.hits().add(hit1);
             return result;
         }
+
     }
 
 }
diff --git a/container-search/src/test/java/com/yahoo/search/test/QueryTestCase.java b/container-search/src/test/java/com/yahoo/search/test/QueryTestCase.java
index 5c5d9006d1a..7cd7e20b76f 100644
--- a/container-search/src/test/java/com/yahoo/search/test/QueryTestCase.java
+++ b/container-search/src/test/java/com/yahoo/search/test/QueryTestCase.java
@@ -552,7 +552,7 @@ public class QueryTestCase {
     @Test
     public void testTracing() {
         Query q = new Query("?query=foo&type=all&traceLevel=2");
-        assertEquals(2, q.getTraceLevel());
+        assertEquals(2, q.getTrace().getLevel());
         q.trace(true, 1, "trace1");
         q.trace(false,2, "trace2");
         q.trace(true, 3, "Ignored");
@@ -571,7 +571,7 @@ public class QueryTestCase {
     @Test
     public void testNullTracing() {
         Query q = new Query("?query=foo&traceLevel=2");
-        assertEquals(2, q.getTraceLevel());
+        assertEquals(2, q.getTrace().getLevel());
         q.trace(false,2, "trace2 ", null);
         Set<String> traces = new HashSet<>();
         for (String trace : q.getContext(true).getTrace().traceNode().descendants(String.class))
@@ -582,8 +582,8 @@ public class QueryTestCase {
     @Test
     public void testExplain() {
         Query q = new Query("?query=foo&explainLevel=2");
-        assertEquals(2, q.getExplainLevel());
-        assertEquals(0, q.getTraceLevel());
+        assertEquals(2, q.getTrace().getExplainLevel());
+        assertEquals(0, q.getTrace().getLevel());
     }
 
     @Test
diff --git a/container-search/src/test/java/com/yahoo/vespa/streamingvisitors/VdsStreamingSearcherTestCase.java b/container-search/src/test/java/com/yahoo/vespa/streamingvisitors/VdsStreamingSearcherTestCase.java
index 861be9a3ade..835235a593c 100644
--- a/container-search/src/test/java/com/yahoo/vespa/streamingvisitors/VdsStreamingSearcherTestCase.java
+++ b/container-search/src/test/java/com/yahoo/vespa/streamingvisitors/VdsStreamingSearcherTestCase.java
@@ -170,10 +170,10 @@ public class VdsStreamingSearcherTestCase {
             } else if (i == 1) {
                 query.getPresentation().setSummary("summary");
             } else if (i == 2) {
-                query.setTraceLevel(100);
+                query.getTrace().setLevel(100);
             } else if (i == 3) {
                 query.getPresentation().setSummary("summary");
-                query.setTraceLevel(100);
+                query.getTrace().setLevel(100);
             }
             queries[i] = query;
         }