Merge pull request #25571 from vespa-engine/havardpe/profiled-iterator

profiled iterator

10 files changed, 252 insertions, 1 deletions

diff --git a/searchlib/CMakeLists.txt b/searchlib/CMakeLists.txt
index 4f6fc90fa37..03429b956a4 100644
--- a/searchlib/CMakeLists.txt
+++ b/searchlib/CMakeLists.txt
@@ -199,6 +199,7 @@ vespa_define_module(
     src/tests/queryeval/nearest_neighbor
     src/tests/queryeval/parallel_weak_and
     src/tests/queryeval/predicate
+    src/tests/queryeval/profiled_iterator
     src/tests/queryeval/same_element
     src/tests/queryeval/simple_phrase
     src/tests/queryeval/sourceblender
diff --git a/searchlib/src/tests/queryeval/profiled_iterator/CMakeLists.txt b/searchlib/src/tests/queryeval/profiled_iterator/CMakeLists.txt
new file mode 100644
index 00000000000..b4c36e7e00c
--- /dev/null
+++ b/searchlib/src/tests/queryeval/profiled_iterator/CMakeLists.txt
@@ -0,0 +1,9 @@
+# Copyright Yahoo. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
+vespa_add_executable(searchlib_queryeval_profiled_iterator_test_app TEST
+    SOURCES
+    profiled_iterator_test.cpp
+    DEPENDS
+    searchlib
+    GTest::GTest
+)
+vespa_add_test(NAME searchlib_queryeval_profiled_iterator_test_app COMMAND searchlib_queryeval_profiled_iterator_test_app)
diff --git a/searchlib/src/tests/queryeval/profiled_iterator/profiled_iterator_test.cpp b/searchlib/src/tests/queryeval/profiled_iterator/profiled_iterator_test.cpp
new file mode 100644
index 00000000000..b89dc8f9e17
--- /dev/null
+++ b/searchlib/src/tests/queryeval/profiled_iterator/profiled_iterator_test.cpp
@@ -0,0 +1,45 @@
+// Copyright Yahoo. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
+
+#include <vespa/vespalib/gtest/gtest.h>
+#include <vespa/vespalib/util/execution_profiler.h>
+#include <vespa/vespalib/data/slime/slime.h>
+#include <vespa/searchlib/queryeval/profiled_iterator.h>
+#include <vespa/searchlib/queryeval/simplesearch.h>
+#include <vespa/searchlib/queryeval/andsearch.h>
+#include <vespa/searchlib/queryeval/orsearch.h>
+
+#include <memory>
+
+using namespace search::queryeval;
+using vespalib::ExecutionProfiler;
+using vespalib::Slime;
+
+SearchIterator::UP create_term(const vespalib::string &name, std::vector<uint32_t> hits) {
+    auto search = std::make_unique<SimpleSearch>(SimpleResult(hits));
+    search->tag(name);
+    return search;
+}
+
+SearchIterator::UP create_iterator_tree() {
+    return AndSearch::create({OrSearch::create({create_term("A", {1,3,5}),
+                                                create_term("B", {2,4,6})}, true),
+                              OrSearch::create({create_term("C", {4,6,8}),
+                                                create_term("D", {5,7,9})}, false)},
+        true);
+}
+
+TEST(ProfiledIteratorTest, iterator_tree_can_be_profiled) {
+    ExecutionProfiler profiler(64);
+    auto root = create_iterator_tree();
+    root = ProfiledIterator::profile(profiler, std::move(root));
+    fprintf(stderr, "%s", root->asString().c_str());
+    SimpleResult expect({4,5,6});
+    SimpleResult actual;
+    actual.searchStrict(*root, 100);
+    EXPECT_EQ(actual, expect);
+    Slime slime;
+    profiler.report(slime.setObject());
+    fprintf(stderr, "%s", slime.toString().c_str());
+}
+
+GTEST_MAIN_RUN_ALL_TESTS()
diff --git a/searchlib/src/vespa/searchlib/queryeval/CMakeLists.txt b/searchlib/src/vespa/searchlib/queryeval/CMakeLists.txt
index 840f5b6b376..adbb06910d7 100644
--- a/searchlib/src/vespa/searchlib/queryeval/CMakeLists.txt
+++ b/searchlib/src/vespa/searchlib/queryeval/CMakeLists.txt
@@ -43,6 +43,7 @@ vespa_add_library(searchlib_queryeval OBJECT
     posting_info.cpp
     predicate_blueprint.cpp
     predicate_search.cpp
+    profiled_iterator.cpp
     ranksearch.cpp
     same_element_blueprint.cpp
     same_element_search.cpp
diff --git a/searchlib/src/vespa/searchlib/queryeval/multisearch.cpp b/searchlib/src/vespa/searchlib/queryeval/multisearch.cpp
index 16f4012f0e7..faf63f54af3 100644
--- a/searchlib/src/vespa/searchlib/queryeval/multisearch.cpp
+++ b/searchlib/src/vespa/searchlib/queryeval/multisearch.cpp
@@ -55,6 +55,14 @@ MultiSearch::initRange(uint32_t beginid, uint32_t endid)
 }
 
 void
+MultiSearch::disclose_children(std::vector<UP*> &dst)
+{
+    for (auto &child: _children) {
+        dst.push_back(&child);
+    }
+}
+
+void
 MultiSearch::visitMembers(vespalib::ObjectVisitor &visitor) const
 {
     visit(visitor, "children", _children);
diff --git a/searchlib/src/vespa/searchlib/queryeval/multisearch.h b/searchlib/src/vespa/searchlib/queryeval/multisearch.h
index 9216391b85d..fea0cb63b5b 100644
--- a/searchlib/src/vespa/searchlib/queryeval/multisearch.h
+++ b/searchlib/src/vespa/searchlib/queryeval/multisearch.h
@@ -41,6 +41,7 @@ public:
     void insert(size_t index, SearchIterator::UP search);
     virtual bool needUnpack(size_t index) const { (void) index; return true; }
     void initRange(uint32_t beginId, uint32_t endId) override;
+    void disclose_children(std::vector<UP*> &dst) override;
 protected:
     MultiSearch();
     void doUnpack(uint32_t docid) override;
diff --git a/searchlib/src/vespa/searchlib/queryeval/profiled_iterator.cpp b/searchlib/src/vespa/searchlib/queryeval/profiled_iterator.cpp
new file mode 100644
index 00000000000..8ae54606146
--- /dev/null
+++ b/searchlib/src/vespa/searchlib/queryeval/profiled_iterator.cpp
@@ -0,0 +1,118 @@
+// Copyright Yahoo. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
+
+#include "profiled_iterator.h"
+#include <vespa/searchlib/common/bitvector.h>
+#include <vespa/vespalib/objects/visit.hpp>
+#include <vespa/vespalib/util/classname.h>
+#include <vespa/vespalib/util/stringfmt.h>
+
+using vespalib::make_string_short::fmt;
+
+namespace search::queryeval {
+
+namespace {
+
+using Profiler = vespalib::ExecutionProfiler;
+
+struct TaskGuard {
+    Profiler &profiler;
+    TaskGuard(Profiler &profiler_in, Profiler::TaskId task) noexcept
+      : profiler(profiler_in) { profiler.start(task); }
+    ~TaskGuard() { profiler.complete(); }
+};
+
+vespalib::string name_of(const auto &obj) {
+    auto name = vespalib::getClassName(obj);
+    auto end = name.find("<");
+    auto ns = name.rfind("::", end);
+    size_t begin = (ns > name.size()) ? 0 : ns + 2;
+    return name.substr(begin, end - begin);
+}
+
+std::unique_ptr<SearchIterator> create(Profiler &profiler,
+                                       const vespalib::string &path,
+                                       std::unique_ptr<SearchIterator> search,
+                                       auto ctor_token)
+{
+    vespalib::string prefix = fmt("%s%s/", path.c_str(), name_of(*search).c_str());
+    return std::make_unique<ProfiledIterator>(profiler, std::move(search),
+                                              profiler.resolve(prefix + "init"),
+                                              profiler.resolve(prefix + "seek"),
+                                              profiler.resolve(prefix + "unpack"),
+                                              profiler.resolve(prefix + "termwise"),
+                                              ctor_token);    
+}
+
+}
+
+void
+ProfiledIterator::initRange(uint32_t begin_id, uint32_t end_id)
+{
+    TaskGuard guard(_profiler, _init_tag);
+    SearchIterator::initRange(begin_id, end_id);
+    _search->initRange(begin_id, end_id);
+    setDocId(_search->getDocId());
+}
+
+void
+ProfiledIterator::doSeek(uint32_t docid)
+{
+    TaskGuard guard(_profiler, _seek_tag);
+    _search->doSeek(docid);
+    setDocId(_search->getDocId());
+}
+
+void
+ProfiledIterator::doUnpack(uint32_t docid)
+{
+    TaskGuard guard(_profiler, _unpack_tag);
+    _search->doUnpack(docid);
+}
+
+std::unique_ptr<BitVector>
+ProfiledIterator::get_hits(uint32_t begin_id)
+{
+    TaskGuard guard(_profiler, _termwise_tag);
+    return _search->get_hits(begin_id);
+}
+
+void
+ProfiledIterator::or_hits_into(BitVector &result, uint32_t begin_id)
+{
+    TaskGuard guard(_profiler, _termwise_tag);
+    _search->or_hits_into(result, begin_id);
+}
+
+void
+ProfiledIterator::and_hits_into(BitVector &result, uint32_t begin_id)
+{
+    TaskGuard guard(_profiler, _termwise_tag);
+    _search->and_hits_into(result, begin_id);
+}
+
+void
+ProfiledIterator::visitMembers(vespalib::ObjectVisitor &visitor) const
+{
+    visit(visitor, "search", _search);
+}
+
+std::unique_ptr<SearchIterator>
+ProfiledIterator::profile(Profiler &profiler, std::unique_ptr<SearchIterator> root)
+{
+    std::vector<UP*> links({&root});
+    std::vector<vespalib::string> paths({"/"});
+    for (size_t offset = 0; offset < links.size(); ++offset) {
+        UP &link = *(links[offset]);
+        vespalib::string path = paths[offset];
+        size_t first_child = links.size();
+        link->disclose_children(links);
+        size_t num_children = links.size() - first_child;
+        for (size_t i = 0; i < num_children; ++i) {
+            paths.push_back(fmt("%s%zu/", path.c_str(), i));
+        }
+        link = create(profiler, path, std::move(link), ctor_tag{});
+    }
+    return root;
+}
+
+}
diff --git a/searchlib/src/vespa/searchlib/queryeval/profiled_iterator.h b/searchlib/src/vespa/searchlib/queryeval/profiled_iterator.h
new file mode 100644
index 00000000000..e8c15501267
--- /dev/null
+++ b/searchlib/src/vespa/searchlib/queryeval/profiled_iterator.h
@@ -0,0 +1,58 @@
+// Copyright Yahoo. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
+
+#pragma once
+
+#include "searchiterator.h"
+#include <vespa/vespalib/util/execution_profiler.h>
+
+namespace search::queryeval {
+
+/**
+ * Wraps a search iterator to profile its operations. Each iterator
+ * has 4 distinct operations that will be profiled separately:
+ *
+ * 'init' -> initRange 
+ * 'seek' -> doSeek
+ * 'unpack' -> doUnpack
+ * 'termwise' -> get_hits, or_hits_into, and_hits_into
+ *
+ * The full name of each profiled task will be the path down the
+ * iterator tree combined with the class name and the operation name.
+ **/
+class ProfiledIterator : public SearchIterator
+{
+private:
+    using Profiler = vespalib::ExecutionProfiler;
+    Profiler &_profiler;
+    std::unique_ptr<SearchIterator> _search;
+    Profiler::TaskId _init_tag;
+    Profiler::TaskId _seek_tag;
+    Profiler::TaskId _unpack_tag;
+    Profiler::TaskId _termwise_tag;
+    struct ctor_tag{};
+public:
+    ProfiledIterator(Profiler &profiler,
+                     std::unique_ptr<SearchIterator> search,
+                     Profiler::TaskId init_tag,
+                     Profiler::TaskId seek_tag,
+                     Profiler::TaskId unpack_tag,
+                     Profiler::TaskId termwise_tag,
+                     ctor_tag) noexcept
+      : _profiler(profiler), _search(std::move(search)),
+        _init_tag(init_tag), _seek_tag(seek_tag),
+        _unpack_tag(unpack_tag), _termwise_tag(termwise_tag) {}
+    void initRange(uint32_t begin_id, uint32_t end_id) override;
+    void doSeek(uint32_t docid) override;
+    void doUnpack(uint32_t docid) override;
+    std::unique_ptr<BitVector> get_hits(uint32_t begin_id) override;
+    void or_hits_into(BitVector &result, uint32_t begin_id) override;
+    void and_hits_into(BitVector &result, uint32_t begin_id) override;
+    void visitMembers(vespalib::ObjectVisitor &visitor) const override;
+    Trinary is_strict() const override { return _search->is_strict(); }
+    Trinary matches_any() const override { return _search->matches_any(); }
+    const PostingInfo *getPostingInfo() const override { return _search->getPostingInfo(); }
+    static std::unique_ptr<SearchIterator> profile(Profiler &profiler,
+                                                   std::unique_ptr<SearchIterator> root);
+};
+
+} // namespace
diff --git a/searchlib/src/vespa/searchlib/queryeval/searchiterator.cpp b/searchlib/src/vespa/searchlib/queryeval/searchiterator.cpp
index a63b8e54eb4..5da3d6c3279 100644
--- a/searchlib/src/vespa/searchlib/queryeval/searchiterator.cpp
+++ b/searchlib/src/vespa/searchlib/queryeval/searchiterator.cpp
@@ -117,6 +117,11 @@ SearchIterator::visitMembers(vespalib::ObjectVisitor &visitor) const
     visit(visitor, "endid", _endid);
 }
 
+void
+SearchIterator::disclose_children(std::vector<UP*> &)
+{
+}
+
 }
 
 //-----------------------------------------------------------------------------
diff --git a/searchlib/src/vespa/searchlib/queryeval/searchiterator.h b/searchlib/src/vespa/searchlib/queryeval/searchiterator.h
index 9ac69735806..0ce0d19a226 100644
--- a/searchlib/src/vespa/searchlib/queryeval/searchiterator.h
+++ b/searchlib/src/vespa/searchlib/queryeval/searchiterator.h
@@ -361,6 +361,12 @@ public:
     // (Undefined -> use seek to find out)
     // number of matches: (False <= Undefined <= True)
     virtual Trinary matches_any() const { return Trinary::Undefined; }
+
+    // Disclose children by giving out references to owning
+    // pointers. This allows re-wiring from the outside, which is
+    // needed for deep decoration used by match profiling. Only
+    // disclose children that are treated as generic SearchIterators.
+    virtual void disclose_children(std::vector<UP*> &dst);
 };
 
 }
@@ -369,4 +375,3 @@ void visit(vespalib::ObjectVisitor &self, const vespalib::string &name,
            const search::queryeval::SearchIterator &obj);
 void visit(vespalib::ObjectVisitor &self, const vespalib::string &name,
            const search::queryeval::SearchIterator *obj);
-