Merge pull request #8681 from vespa-engine/balder/trace-backend

Balder/trace backend

18 files changed, 322 insertions, 107 deletions

diff --git a/searchlib/src/tests/engine/searchapi/searchapi_test.cpp b/searchlib/src/tests/engine/searchapi/searchapi_test.cpp
index a517890620c..626435360a0 100644
--- a/searchlib/src/tests/engine/searchapi/searchapi_test.cpp
+++ b/searchlib/src/tests/engine/searchapi/searchapi_test.cpp
@@ -1,10 +1,12 @@
 // Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
-#include <vespa/log/log.h>
-LOG_SETUP("searchapi_test");
+
 #include <vespa/vespalib/testkit/testapp.h>
 #include <vespa/searchlib/common/packets.h>
 #include <vespa/searchlib/engine/searchapi.h>
 #include <vespa/searchlib/engine/packetconverter.h>
+#include <vespa/vespalib/data/slime/slime.h>
+#include <vespa/log/log.h>
+LOG_SETUP("searchapi_test");
 
 using namespace search::engine;
 using namespace search::fs4transport;
@@ -28,18 +30,8 @@ template <typename T> void copyPacket(T &src, T &dst) {
 
 } // namespace <unnamed>
 
-class Test : public vespalib::TestApp
-{
-public:
-    void propertyNames();
-    void convertToRequest();
-    void convertFromReply();
-    int Main() override;
-};
-
-void
-Test::propertyNames()
-{
+
+TEST("propertyNames") {
     EXPECT_EQUAL(search::MapNames::RANK, "rank");
     EXPECT_EQUAL(search::MapNames::FEATURE, "feature");
     EXPECT_EQUAL(search::MapNames::HIGHLIGHTTERMS, "highlightterms");
@@ -47,9 +39,7 @@ Test::propertyNames()
     EXPECT_EQUAL(search::MapNames::CACHES, "caches");
 }
 
-void
-Test::convertToRequest()
-{
+TEST("convertToReques") {
     FS4Packet_QUERYX src;
     src._offset = 2u;
     src._maxhits = 3u;
@@ -116,9 +106,7 @@ Test::convertToRequest()
     }
 }
 
-void
-Test::convertFromReply()
-{
+TEST("convertFromReply") {
     SearchReply src;
     src.offset = 1u;
     src.totalHitCount = 2u;
@@ -240,14 +228,46 @@ Test::convertFromReply()
     }
 }
 
-int
-Test::Main()
-{
-    TEST_INIT("searchapi_test");
-    propertyNames();
-    convertToRequest();
-    convertFromReply();
-    TEST_DONE();
+void verify(vespalib::stringref expected, const vespalib::Slime & slime) {
+    vespalib::Slime expectedSlime;
+    vespalib::slime::JsonFormat::decode(expected, expectedSlime);
+    EXPECT_EQUAL(expectedSlime, slime);
+}
+
+TEST("verify trace") {
+    Trace t(7);
+    verify("{"
+           "    traces: ["
+           "    ],"
+           "    creation_time: 7"
+           "}",
+           t.getSlime());
+
+    t.createCursor("tag_a");
+    verify("{"
+           "    traces: ["
+           "        {"
+           "            tag: 'tag_a'"
+           "        }"
+           "    ],"
+           "    creation_time: 7"
+           "}",
+           t.getSlime());
+    Trace::Cursor & tagB = t.createCursor("tag_b");
+    tagB.setLong("long", 19);
+    verify("{"
+           "    traces: ["
+           "        {"
+           "            tag: 'tag_a'"
+           "        },"
+           "        {"
+           "            tag: 'tag_b',"
+           "            long: 19"
+           "        }"
+           "    ],"
+           "    creation_time: 7"
+           "}",
+           t.getSlime());
 }
 
-TEST_APPHOOK(Test);
+TEST_MAIN() { TEST_RUN_ALL(); }
diff --git a/searchlib/src/tests/queryeval/blueprint/blueprint_test.cpp b/searchlib/src/tests/queryeval/blueprint/blueprint_test.cpp
index e5ee83507ae..108b7b9d20d 100644
--- a/searchlib/src/tests/queryeval/blueprint/blueprint_test.cpp
+++ b/searchlib/src/tests/queryeval/blueprint/blueprint_test.cpp
@@ -5,6 +5,7 @@
 #include <vespa/searchlib/queryeval/intermediate_blueprints.h>
 #include <vespa/vespalib/objects/objectdumper.h>
 #include <vespa/vespalib/objects/visit.h>
+#include <vespa/vespalib/data/slime/slime.h>
 #include <algorithm>
 
 #include <vespa/log/log.h>
@@ -178,6 +179,7 @@ public:
     void testSearchCreation();
     void testBlueprintMakeNew();
     void requireThatAsStringWorks();
+    void requireThatAsSlimeWorks();
     void requireThatVisitMembersWorks();
     void requireThatDocIdLimitInjectionWorks();
     int Main() override;
@@ -698,6 +700,58 @@ getExpectedBlueprint()
            "}\n";
 }
 
+vespalib::string
+getExpectedSlimeBlueprint() {
+    return "{"
+           "    '[type]': '(anonymous namespace)::MyOr',"
+           "     isTermLike: true,"
+           "     fields: {"
+           "        '[type]': 'FieldList',"
+           "        '[0]': {"
+           "            '[type]': 'Field',"
+           "            fieldId: 5,"
+           "            handle: 7,"
+           "            isFilter: false"
+           "        }"
+           "    },"
+           "    estimate: {"
+           "        '[type]': 'HitEstimate',"
+           "        empty: false,"
+           "        estHits: 9,"
+           "        tree_size: 2,"
+           "        allow_termwise_eval: 0"
+           "    },"
+           "    sourceId: 4294967295,"
+           "    docid_limit: 0,"
+           "    children: {"
+           "        '[type]': 'std::vector',"
+           "        '[0]': {"
+           "            isTermLike: true,"
+           "            fields: {"
+           "                '[type]': 'FieldList',"
+           "                '[0]': {"
+           "                    '[type]': 'Field',"
+           "                    fieldId: 5,"
+           "                    handle: 7,"
+           "                    isFilter: false"
+           "                }"
+           "            },"
+           "            '[type]': '(anonymous namespace)::MyTerm',"
+           "            estimate: {"
+           "                '[type]': 'HitEstimate',"
+           "                empty: false,"
+           "                estHits: 9,"
+           "                tree_size: 1,"
+           "                allow_termwise_eval: 1"
+           "            },"
+           "            sourceId: 4294967295,"
+           "            docid_limit: 0"
+           "        }"
+           "    }"
+           "}";
+}
+
+
 struct BlueprintFixture
 {
     MyOr _blueprint;
@@ -714,6 +768,18 @@ Test::requireThatAsStringWorks()
 }
 
 void
+Test::requireThatAsSlimeWorks()
+{
+    BlueprintFixture f;
+    vespalib::Slime slime;
+    f._blueprint.asSlime(vespalib::slime::SlimeInserter(slime));
+    auto s = slime.toString();
+    vespalib::Slime expectedSlime;
+    vespalib::slime::JsonFormat::decode(getExpectedSlimeBlueprint(), expectedSlime);
+    EXPECT_EQUAL(expectedSlime, slime);
+}
+
+void
 Test::requireThatVisitMembersWorks()
 {
     BlueprintFixture f;
@@ -749,6 +815,7 @@ Test::Main()
     testSearchCreation();
     testBlueprintMakeNew();
     requireThatAsStringWorks();
+    requireThatAsSlimeWorks();
     requireThatVisitMembersWorks();
     requireThatDocIdLimitInjectionWorks();
     TEST_DONE();
diff --git a/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector.cpp b/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector.cpp
index 0ba4bc814d5..9e3b0bbde3e 100644
--- a/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector.cpp
+++ b/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector.cpp
@@ -39,8 +39,7 @@ ImportedAttributeVector::ImportedAttributeVector(vespalib::stringref name,
 {
 }
 
-ImportedAttributeVector::~ImportedAttributeVector() {
-}
+ImportedAttributeVector::~ImportedAttributeVector() = default;
 
 std::unique_ptr<AttributeReadGuard>
 ImportedAttributeVector::makeReadGuard(bool stableEnumGuard) const
diff --git a/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector.h b/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector.h
index e6356866ed9..33afaaf7f1e 100644
--- a/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector.h
+++ b/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector.h
@@ -6,11 +6,9 @@
 #include <vespa/vespalib/stllike/string.h>
 #include <memory>
 
-namespace search {
+namespace search { struct IDocumentMetaStoreContext; }
 
-struct IDocumentMetaStoreContext;
-
-namespace attribute {
+namespace search::attribute {
 
 class BitVectorSearchCache;
 class ReadableAttributeVector;
@@ -63,7 +61,7 @@ public:
         return _name;
     }
 
-    virtual std::unique_ptr<AttributeReadGuard> makeReadGuard(bool stableEnumGuard) const override;
+    std::unique_ptr<AttributeReadGuard> makeReadGuard(bool stableEnumGuard) const override;
 
 protected:
     vespalib::string                           _name;
@@ -75,4 +73,3 @@ protected:
 };
 
 }
-}
diff --git a/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector_read_guard.cpp b/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector_read_guard.cpp
index 428b14671cd..50fa1ffded3 100644
--- a/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector_read_guard.cpp
+++ b/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector_read_guard.cpp
@@ -6,8 +6,7 @@
 #include "reference_attribute.h"
 #include <vespa/searchlib/query/queryterm.h>
 
-namespace search {
-namespace attribute {
+namespace search::attribute {
 
 ImportedAttributeVectorReadGuard::ImportedAttributeVectorReadGuard(
         const ImportedAttributeVector &imported_attribute,
@@ -24,8 +23,7 @@ ImportedAttributeVectorReadGuard::ImportedAttributeVectorReadGuard(
     _targetLids = _reference_attribute.getTargetLids();
 }
 
-ImportedAttributeVectorReadGuard::~ImportedAttributeVectorReadGuard() {
-}
+ImportedAttributeVectorReadGuard::~ImportedAttributeVectorReadGuard() = default;
 
 const vespalib::string& ImportedAttributeVectorReadGuard::getName() const {
     return _imported_attribute.getName();
@@ -169,4 +167,3 @@ long ImportedAttributeVectorReadGuard::onSerializeForDescendingSort(DocId doc,
 }
 
 }
-}
diff --git a/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector_read_guard.h b/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector_read_guard.h
index 4cf4d5b64c1..f130a095006 100644
--- a/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector_read_guard.h
+++ b/searchlib/src/vespa/searchlib/attribute/imported_attribute_vector_read_guard.h
@@ -45,49 +45,48 @@ protected:
     }
 
 public:
-    ImportedAttributeVectorReadGuard(const ImportedAttributeVector &imported_attribute,
-                                     bool stableEnumGuard);
-    ~ImportedAttributeVectorReadGuard();
+    ImportedAttributeVectorReadGuard(const ImportedAttributeVector &imported_attribute, bool stableEnumGuard);
+    ~ImportedAttributeVectorReadGuard() override;
 
-    virtual const vespalib::string &getName() const override;
-    virtual uint32_t getNumDocs() const override;
-    virtual uint32_t getValueCount(uint32_t doc) const override;
-    virtual uint32_t getMaxValueCount() const override;
-    virtual largeint_t getInt(DocId doc) const override;
-    virtual double getFloat(DocId doc) const override;
-    virtual const char *getString(DocId doc, char *buffer, size_t sz) const override;
-    virtual EnumHandle getEnum(DocId doc) const override;
-    virtual uint32_t get(DocId docId, largeint_t *buffer, uint32_t sz) const override;
-    virtual uint32_t get(DocId docId, double *buffer, uint32_t sz) const override;
-    virtual uint32_t get(DocId docId, const char **buffer, uint32_t sz) const override;
-    virtual uint32_t get(DocId docId, EnumHandle *buffer, uint32_t sz) const override;
-    virtual uint32_t get(DocId docId, WeightedInt *buffer, uint32_t sz) const override;
-    virtual uint32_t get(DocId docId, WeightedFloat *buffer, uint32_t sz) const override;
-    virtual uint32_t get(DocId docId, WeightedString *buffer, uint32_t sz) const override;
-    virtual uint32_t get(DocId docId, WeightedConstChar *buffer, uint32_t sz) const override;
-    virtual uint32_t get(DocId docId, WeightedEnum *buffer, uint32_t sz) const override;
-    virtual bool findEnum(const char * value, EnumHandle & e) const override;
-    virtual std::vector<EnumHandle> findFoldedEnums(const char *value) const override;
+    const vespalib::string &getName() const override;
+    uint32_t getNumDocs() const override;
+    uint32_t getValueCount(uint32_t doc) const override;
+    uint32_t getMaxValueCount() const override;
+    largeint_t getInt(DocId doc) const override;
+    double getFloat(DocId doc) const override;
+    const char *getString(DocId doc, char *buffer, size_t sz) const override;
+    EnumHandle getEnum(DocId doc) const override;
+    uint32_t get(DocId docId, largeint_t *buffer, uint32_t sz) const override;
+    uint32_t get(DocId docId, double *buffer, uint32_t sz) const override;
+    uint32_t get(DocId docId, const char **buffer, uint32_t sz) const override;
+    uint32_t get(DocId docId, EnumHandle *buffer, uint32_t sz) const override;
+    uint32_t get(DocId docId, WeightedInt *buffer, uint32_t sz) const override;
+    uint32_t get(DocId docId, WeightedFloat *buffer, uint32_t sz) const override;
+    uint32_t get(DocId docId, WeightedString *buffer, uint32_t sz) const override;
+    uint32_t get(DocId docId, WeightedConstChar *buffer, uint32_t sz) const override;
+    uint32_t get(DocId docId, WeightedEnum *buffer, uint32_t sz) const override;
+    bool findEnum(const char * value, EnumHandle & e) const override;
+    std::vector<EnumHandle> findFoldedEnums(const char *value) const override;
 
-    virtual const char * getStringFromEnum(EnumHandle e) const override;
-    virtual std::unique_ptr<ISearchContext> createSearchContext(std::unique_ptr<QueryTermSimple> term,
-                                                                const SearchContextParams &params) const override;
-    virtual const IDocumentWeightAttribute *asDocumentWeightAttribute() const override;
-    virtual const tensor::ITensorAttribute *asTensorAttribute() const override;
-    virtual BasicType::Type getBasicType() const override;
-    virtual size_t getFixedWidth() const override;
-    virtual CollectionType::Type getCollectionType() const override;
-    virtual bool hasEnum() const override;
-    virtual bool getIsFilter() const override;
-    virtual bool getIsFastSearch() const override;
-    virtual uint32_t getCommittedDocIdLimit() const override;
-    virtual bool isImported() const override;
+    const char * getStringFromEnum(EnumHandle e) const override;
+    std::unique_ptr<ISearchContext> createSearchContext(std::unique_ptr<QueryTermSimple> term,
+                                                        const SearchContextParams &params) const override;
+    const IDocumentWeightAttribute *asDocumentWeightAttribute() const override;
+    const tensor::ITensorAttribute *asTensorAttribute() const override;
+    BasicType::Type getBasicType() const override;
+    size_t getFixedWidth() const override;
+    CollectionType::Type getCollectionType() const override;
+    bool hasEnum() const override;
+    bool getIsFilter() const override;
+    bool getIsFastSearch() const override;
+    uint32_t getCommittedDocIdLimit() const override;
+    bool isImported() const override;
 
 protected:
-    virtual long onSerializeForAscendingSort(DocId doc, void * serTo, long available,
-                                             const common::BlobConverter * bc) const override;
-    virtual long onSerializeForDescendingSort(DocId doc, void * serTo, long available,
-                                              const common::BlobConverter * bc) const override;
+    long onSerializeForAscendingSort(DocId doc, void * serTo, long available,
+                                     const common::BlobConverter * bc) const override;
+    long onSerializeForDescendingSort(DocId doc, void * serTo, long available,
+                                      const common::BlobConverter * bc) const override;
 };
 
 }
diff --git a/searchlib/src/vespa/searchlib/engine/CMakeLists.txt b/searchlib/src/vespa/searchlib/engine/CMakeLists.txt
index 95b47b991af..e475d786a60 100644
--- a/searchlib/src/vespa/searchlib/engine/CMakeLists.txt
+++ b/searchlib/src/vespa/searchlib/engine/CMakeLists.txt
@@ -13,6 +13,7 @@ vespa_add_library(searchlib_engine OBJECT
     searchreply.cpp
     searchrequest.cpp
     source_description.cpp
+    trace.cpp
     transport_metrics.cpp
     transportserver.cpp
     DEPENDS
diff --git a/searchlib/src/vespa/searchlib/engine/packetconverter.cpp b/searchlib/src/vespa/searchlib/engine/packetconverter.cpp
index e6fb37223d6..d87d9888aae 100644
--- a/searchlib/src/vespa/searchlib/engine/packetconverter.cpp
+++ b/searchlib/src/vespa/searchlib/engine/packetconverter.cpp
@@ -1,9 +1,14 @@
 // Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
 
 #include "packetconverter.h"
+#include <vespa/searchlib/fef/indexproperties.h>
+
 #include <vespa/log/log.h>
 LOG_SETUP(".engine.packetconverter");
 
+using search::fef::Property;
+using search::fef::Properties;
+
 namespace {
 
 bool checkFeature(uint32_t features, uint32_t mask) {
@@ -14,8 +19,8 @@ struct FS4PropertiesBuilder : public search::fef::IPropertiesVisitor {
     uint32_t idx;
     search::fs4transport::FS4Properties &props;
     FS4PropertiesBuilder(search::fs4transport::FS4Properties &p) : idx(0), props(p) {}
-    void visitProperty(const search::fef::Property::Value &key,
-                               const search::fef::Property &values) override
+    void visitProperty(const Property::Value &key,
+                       const Property &values) override
     {
         for (uint32_t i = 0; i < values.size(); ++i) {
             props.setKey(idx, key.data(), key.size());
@@ -39,7 +44,7 @@ PacketConverter::fillPacketProperties(const PropertiesMap &source, PropsVector&
     PropertiesMap::ITR end = source.end();
     for (uint32_t i = 0; itr != end; ++itr, ++i) {
         const vespalib::string &name = itr->first;
-        const search::fef::Properties &values = itr->second;
+        const Properties &values = itr->second;
         target[i].setName(name.c_str(), name.size());
         target[i].allocEntries(values.numValues());
         FS4PropertiesBuilder builder(target[i]);
@@ -58,9 +63,8 @@ PacketConverter::toSearchRequest(const QUERYX &packet, SearchRequest &request)
     request.queryFlags = packet.getQueryFlags();
     request.ranking    = packet._ranking;
 
-    for (uint32_t i = 0; i < packet._propsVector.size(); ++i) {
-        const FS4Properties &src = packet._propsVector[i];
-        search::fef::Properties &dst = request.propertiesMap.lookupCreate(src.getName());
+    for (const FS4Properties &src : packet._propsVector) {
+        Properties &dst = request.propertiesMap.lookupCreate(src.getName());
         for (uint32_t e = 0; e < src.size(); ++e) {
             dst.add(vespalib::stringref(src.getKey(e), src.getKeyLen(e)),
                     vespalib::stringref(src.getValue(e), src.getValueLen(e)));
@@ -72,6 +76,7 @@ PacketConverter::toSearchRequest(const QUERYX &packet, SearchRequest &request)
     request.location        = packet._location;
     request.stackItems      = packet._numStackItems;
     request.stackDump.assign( packet._stackDump.begin(), packet._stackDump.end());
+    request.setTraceLevel(search::fef::indexproperties::trace::Level::lookup(request.propertiesMap.modelOverrides()));
 }
 
 void
@@ -100,7 +105,7 @@ PacketConverter::fromSearchReply(const SearchReply &reply, QUERYRESULTX &packet)
     packet._totNumDocs = reply.totalHitCount;
     packet._maxRank    = reply.maxRank;
     packet.setDistributionKey(reply.getDistributionKey());
-    if (reply.sortIndex.size() > 0) {
+    if ( ! reply.sortIndex.empty()) {
         packet._features |= QRF_SORTDATA;
         uint32_t idxCnt = reply.sortIndex.size();
         LOG_ASSERT(reply.sortIndex.size() == reply.hits.size()+1);
@@ -112,7 +117,7 @@ PacketConverter::fromSearchReply(const SearchReply &reply, QUERYRESULTX &packet)
         }
         memcpy(packet._sortData, &(reply.sortData[0]), reply.sortData.size());
     }
-    if (reply.groupResult.size() > 0) {
+    if ( ! reply.groupResult.empty()) {
         packet._features |= QRF_GROUPDATA;
         packet.AllocateGroupData(reply.groupResult.size());
         memcpy(packet._groupData, &(reply.groupResult[0]), reply.groupResult.size());
@@ -123,8 +128,10 @@ PacketConverter::fromSearchReply(const SearchReply &reply, QUERYRESULTX &packet)
     packet._coverageDegradeReason = reply.coverage.getDegradeReason();
     packet.setNodesQueried(reply.coverage.getNodesQueried());
     packet.setNodesReplied(reply.coverage.getNodesReplied());
-    if (reply.request && (reply.request->queryFlags & QFLAG_COVERAGE_NODES)) {
-        packet._features |= QRF_COVERAGE_NODES;
+    if (reply.request) {
+        if (reply.request->queryFlags & QFLAG_COVERAGE_NODES) {
+            packet._features |= QRF_COVERAGE_NODES;
+        }
     }
     if (reply.useWideHits) {
         packet._features |= QRF_MLD;
@@ -150,9 +157,8 @@ PacketConverter::toDocsumRequest(const GETDOCSUMSX &packet, DocsumRequest &reque
     request.ranking           = packet._ranking;
     request.queryFlags        = packet._qflags;
     request.resultClassName   = packet._resultClassName;
-    for (uint32_t i = 0; i < packet._propsVector.size(); ++i) {
-        const FS4Properties &src = packet._propsVector[i];
-        search::fef::Properties &dst = request.propertiesMap.lookupCreate(src.getName());
+    for (const FS4Properties &src : packet._propsVector) {
+        Properties &dst = request.propertiesMap.lookupCreate(src.getName());
         for (uint32_t e = 0; e < src.size(); ++e) {
             dst.add(vespalib::stringref(src.getKey(e), src.getKeyLen(e)),
                     vespalib::stringref(src.getValue(e), src.getValueLen(e)));
@@ -169,8 +175,7 @@ PacketConverter::toDocsumRequest(const GETDOCSUMSX &packet, DocsumRequest &reque
         request.hits[i].gid      = packet._docid[i]._gid;
         request.hits[i].path     = packet._docid[i]._partid;
     }
-    search::fef::Property sessionId =
-        request.propertiesMap.rankProperties().lookup("sessionId");
+    Property sessionId = request.propertiesMap.rankProperties().lookup("sessionId");
     if (sessionId.found()) {
         vespalib::string id = sessionId.get();
         request.sessionId.assign(id.begin(), id.end());
@@ -198,7 +203,7 @@ PacketConverter::toDocsumReplyElement(const DOCSUM &packet, DocsumReply::Docsum
 void
 PacketConverter::fromDocsumReplyElement(const DocsumReply::Docsum &docsum, DOCSUM &packet)
 {
-    if (docsum.data.get() != 0) {
+    if (docsum.data.get() != nullptr) {
         packet.SetBuf(docsum.data.c_str(), docsum.data.size());
     }
     packet.setGid(docsum.gid);
diff --git a/searchlib/src/vespa/searchlib/engine/propertiesmap.cpp b/searchlib/src/vespa/searchlib/engine/propertiesmap.cpp
index b09813c0258..4726a3b9c27 100644
--- a/searchlib/src/vespa/searchlib/engine/propertiesmap.cpp
+++ b/searchlib/src/vespa/searchlib/engine/propertiesmap.cpp
@@ -11,7 +11,7 @@ PropertiesMap::PropertiesMap()
     : _propertiesMap()
 { }
 
-PropertiesMap::~PropertiesMap() { }
+PropertiesMap::~PropertiesMap() = default;
 
 fef::Properties &
 PropertiesMap::lookupCreate(vespalib::stringref name)
diff --git a/searchlib/src/vespa/searchlib/engine/request.cpp b/searchlib/src/vespa/searchlib/engine/request.cpp
index 8f4aa427988..fd4a46ccc43 100644
--- a/searchlib/src/vespa/searchlib/engine/request.cpp
+++ b/searchlib/src/vespa/searchlib/engine/request.cpp
@@ -8,12 +8,14 @@ namespace search::engine {
 Request::Request(const fastos::TimeStamp &start_time)
     : _startTime(start_time),
       _timeOfDoom(fastos::TimeStamp(fastos::TimeStamp::FUTURE)),
-      ranking(),
+      _traceLevel(0),
       queryFlags(0),
+      ranking(),
       location(),
       propertiesMap(),
       stackItems(0),
-      stackDump()
+      stackDump(),
+      _trace(start_time)
 {
 }
 
diff --git a/searchlib/src/vespa/searchlib/engine/request.h b/searchlib/src/vespa/searchlib/engine/request.h
index 02ab75fe509..521a5be39fc 100644
--- a/searchlib/src/vespa/searchlib/engine/request.h
+++ b/searchlib/src/vespa/searchlib/engine/request.h
@@ -3,6 +3,7 @@
 #pragma once
 
 #include "propertiesmap.h"
+#include "trace.h"
 #include <vespa/fastos/timestamp.h>
 
 namespace search::engine {
@@ -11,6 +12,8 @@ class Request
 {
 public:
     Request(const fastos::TimeStamp &start_time);
+    Request(const Request &) = delete;
+    Request & operator =(const Request &) = delete;
     virtual ~Request();
     void setTimeout(const fastos::TimeStamp & timeout);
     fastos::TimeStamp getStartTime() const { return _startTime; }
@@ -26,17 +29,24 @@ public:
 
     bool should_drop_sort_data() const;
 
+    uint32_t getTraceLevel() const { return _traceLevel; }
+    Request & setTraceLevel(uint32_t traceLevel) { _traceLevel = traceLevel; return *this; }
+
+    Trace & trace() const { return _trace; }
 private:
     const fastos::TimeStamp _startTime;
     fastos::TimeStamp       _timeOfDoom;
+    uint32_t                _traceLevel;
 public:
     /// Everything here should move up to private section and have accessors
-    vespalib::string   ranking;
     uint32_t           queryFlags;
+    vespalib::string   ranking;
     vespalib::string   location;
     PropertiesMap      propertiesMap;
     uint32_t           stackItems;
     std::vector<char>  stackDump;
+private:
+    mutable Trace      _trace;
 };
 
 }
diff --git a/searchlib/src/vespa/searchlib/engine/searchrequest.cpp b/searchlib/src/vespa/searchlib/engine/searchrequest.cpp
index 7159c83716b..b558e07480d 100644
--- a/searchlib/src/vespa/searchlib/engine/searchrequest.cpp
+++ b/searchlib/src/vespa/searchlib/engine/searchrequest.cpp
@@ -17,20 +17,20 @@ SearchRequest::SearchRequest(const fastos::TimeStamp &start_time)
       sessionId()
 { }
 
-SearchRequest::~SearchRequest() {}
+SearchRequest::~SearchRequest() = default;
 
 void SearchRequest::Source::lazyDecode() const
 {
-    if ((_request.get() == NULL) && (_fs4Packet != NULL)) {
-        _request.reset(new SearchRequest(_start));
+    if (!_request && (_fs4Packet != nullptr)) {
+        _request = std::make_unique<SearchRequest>(_start);
         PacketConverter::toSearchRequest(*_fs4Packet, *_request);
         _fs4Packet->Free();
-        _fs4Packet = NULL;
+        _fs4Packet = nullptr;
     }
 }
 
 SearchRequest::Source::~Source() {
-    if (_fs4Packet != NULL) {
+    if (_fs4Packet != nullptr) {
         _fs4Packet->Free();
     }
 }
diff --git a/searchlib/src/vespa/searchlib/engine/trace.cpp b/searchlib/src/vespa/searchlib/engine/trace.cpp
new file mode 100644
index 00000000000..e12fb9affa6
--- /dev/null
+++ b/searchlib/src/vespa/searchlib/engine/trace.cpp
@@ -0,0 +1,31 @@
+// Copyright 2019 Oath Inc. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
+
+#include "trace.h"
+#include <vespa/vespalib/data/slime/slime.h>
+#include <vespa/fastos/timestamp.h>
+
+namespace search::engine {
+
+Trace::Trace(const fastos::TimeStamp &start_time)
+    : _trace(std::make_unique<vespalib::Slime>()),
+      _root(_trace->setObject()),
+      _traces(_root.setArray("traces"))
+{
+   _root.setLong("creation_time", start_time);
+}
+
+Trace::~Trace() = default;
+
+Trace::Cursor &
+Trace::createCursor(vespalib::stringref name) {
+    Cursor & trace = _traces.addObject();
+    trace.setString("tag", name);
+    return trace;
+}
+
+vespalib::string
+Trace::toString() const {
+    return _trace->toString();
+}
+
+}
diff --git a/searchlib/src/vespa/searchlib/engine/trace.h b/searchlib/src/vespa/searchlib/engine/trace.h
new file mode 100644
index 00000000000..09d61c0f199
--- /dev/null
+++ b/searchlib/src/vespa/searchlib/engine/trace.h
@@ -0,0 +1,39 @@
+// Copyright 2019 Oath Inc. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
+
+#pragma once
+
+#include <vespa/vespalib/stllike/string.h>
+
+namespace fastos { class TimeStamp; }
+namespace vespalib { class Slime; }
+namespace vespalib::slime { class Cursor; }
+
+namespace search::engine {
+
+    /**
+     * Used for adding traces to a request. Acquire a new Cursor for everytime you want to trace something.
+     * Note that it is not thread safe. All use of any cursor aquired must be thread safe.
+     */
+class Trace
+{
+public:
+    using Cursor = vespalib::slime::Cursor;
+    Trace(const fastos::TimeStamp &start_time);
+    ~Trace();
+
+    /**
+     * Will give you a trace entry. It will also add a timestamp relative to the creation of the trace.
+     * @param name
+     * @return a Cursor to use for further tracing.
+     */
+    Cursor & createCursor(vespalib::stringref name);
+    vespalib::string toString() const;
+    Cursor & getRoot() const { return _root; }
+    vespalib::Slime & getSlime() const { return *_trace; }
+private:
+    std::unique_ptr<vespalib::Slime> _trace;
+    Cursor & _root;
+    Cursor & _traces;
+};
+
+}
diff --git a/searchlib/src/vespa/searchlib/fef/indexproperties.cpp b/searchlib/src/vespa/searchlib/fef/indexproperties.cpp
index 5cd6c479d24..fd73ce5a0f0 100644
--- a/searchlib/src/vespa/searchlib/fef/indexproperties.cpp
+++ b/searchlib/src/vespa/searchlib/fef/indexproperties.cpp
@@ -388,6 +388,24 @@ DiversityCutoffStrategy::lookup(const Properties &props, const vespalib::string
     return lookupString(props, NAME, defaultValue);
 }
 
+}
+
+namespace trace {
+
+const vespalib::string Level::NAME("tracelevel");
+const uint32_t Level::DEFAULT_VALUE(0);
+
+uint32_t
+Level::lookup(const Properties &props)
+{
+    return lookup(props, DEFAULT_VALUE);
+}
+
+uint32_t
+Level::lookup(const Properties &props, uint32_t defaultValue)
+{
+    return lookupUint32(props, NAME, defaultValue);
+}
 
 }
 
diff --git a/searchlib/src/vespa/searchlib/fef/indexproperties.h b/searchlib/src/vespa/searchlib/fef/indexproperties.h
index 8b78e347a90..23efe514d68 100644
--- a/searchlib/src/vespa/searchlib/fef/indexproperties.h
+++ b/searchlib/src/vespa/searchlib/fef/indexproperties.h
@@ -310,6 +310,20 @@ namespace matchphase {
 
 } // namespace matchphase
 
+namespace trace {
+
+    /**
+ * Property for the heap size used in the hit collector.
+ **/
+    struct Level {
+        static const vespalib::string NAME;
+        static const uint32_t DEFAULT_VALUE;
+        static uint32_t lookup(const Properties &props);
+        static uint32_t lookup(const Properties &props, uint32_t defaultValue);
+    };
+
+}
+
 
 namespace hitcollector {
 
diff --git a/searchlib/src/vespa/searchlib/queryeval/blueprint.cpp b/searchlib/src/vespa/searchlib/queryeval/blueprint.cpp
index c99e07cd355..3f3b4a2300e 100644
--- a/searchlib/src/vespa/searchlib/queryeval/blueprint.cpp
+++ b/searchlib/src/vespa/searchlib/queryeval/blueprint.cpp
@@ -6,7 +6,9 @@
 #include "equiv_blueprint.h"
 #include <vespa/vespalib/objects/visit.hpp>
 #include <vespa/vespalib/objects/objectdumper.h>
+#include <vespa/vespalib/objects/object2slime.h>
 #include <vespa/vespalib/util/classname.h>
+#include <vespa/vespalib/data/slime/inserter.h>
 #include <map>
 
 #include <vespa/log/log.h>
@@ -117,6 +119,15 @@ Blueprint::asString() const
     return dumper.toString();
 }
 
+vespalib::slime::Cursor &
+Blueprint::asSlime(const vespalib::slime::Inserter & inserter) const
+{
+    vespalib::slime::Cursor & cursor = inserter.insertObject();
+    vespalib::Object2Slime dumper(cursor);
+    visit(dumper, "", this);
+    return cursor;
+}
+
 vespalib::string
 Blueprint::getClassName() const
 {
diff --git a/searchlib/src/vespa/searchlib/queryeval/blueprint.h b/searchlib/src/vespa/searchlib/queryeval/blueprint.h
index 165f592867a..4b60e7d0d8b 100644
--- a/searchlib/src/vespa/searchlib/queryeval/blueprint.h
+++ b/searchlib/src/vespa/searchlib/queryeval/blueprint.h
@@ -9,7 +9,11 @@
 #include <vespa/searchlib/fef/termfieldmatchdata.h>
 #include <vespa/searchlib/fef/termfieldmatchdataarray.h>
 
-namespace vespalib { class ObjectVisitor; };
+namespace vespalib { class ObjectVisitor; }
+namespace vespalib::slime {
+    class Cursor;
+    class Inserter;
+}
 
 namespace search::queryeval {
 
@@ -173,6 +177,7 @@ public:
 
     // for debug dumping
     vespalib::string asString() const;
+    vespalib::slime::Cursor & asSlime(const vespalib::slime::Inserter & cursor) const;
     virtual vespalib::string getClassName() const;
     virtual void visitMembers(vespalib::ObjectVisitor &visitor) const;
     virtual bool isEquiv() const { return false; }