support mapping names in execution profiling output

use feature descriptions rather than raw feature names
drop single quotes from feature descriptions

3 files changed, 91 insertions, 64 deletions

diff --git a/vespalib/src/tests/execution_profiler/execution_profiler_test.cpp b/vespalib/src/tests/execution_profiler/execution_profiler_test.cpp
index 565b8572201..f41aaffd90d 100644
--- a/vespalib/src/tests/execution_profiler/execution_profiler_test.cpp
+++ b/vespalib/src/tests/execution_profiler/execution_profiler_test.cpp
@@ -40,46 +40,27 @@ void foo(Profiler &profiler) {
     fox(profiler);
     profiler.complete();
 }
-    
-const Inspector *find_child(const Inspector &arr, const std::pair<vespalib::string,size_t> &entry) {
-    struct MyArrayTraverser : public vespalib::slime::ArrayTraverser {
-        const Inspector *node = nullptr;
-        const std::pair<vespalib::string,size_t> &needle;
-        MyArrayTraverser(const std::pair<vespalib::string,size_t> &needle_in) : needle(needle_in) {}
-        void entry(size_t, const Inspector &obj) override {
-            if ((obj["name"].asString().make_string() == needle.first) &&
-                (obj["count"].asLong() == int64_t(needle.second)))
-            {
-                assert(node == nullptr);
-                node = &obj;
-            }
-        }
-    };
-    MyArrayTraverser traverser(entry);
-    arr.traverse(traverser);
-    return traverser.node;
-}
 
-bool verify_path(const Inspector &root, const std::vector<std::pair<vespalib::string,size_t>> &path) {    
-    const Inspector *pos = &root;
-    bool first = true;
-    for (const auto &entry: path) {
-        if (first) {
-            pos = find_child((*pos)["roots"], entry);
-        } else {
-            pos = find_child((*pos)["children"], entry);
-        }
-        first = false;
-        if (pos == nullptr) {
-            fprintf(stderr, "could not find entry [%s, %zu]\n", entry.first.c_str(), entry.second);
-            return false;
-        }
+template <typename PathPos>
+bool find_path(const Inspector &self, PathPos pos, PathPos end, bool first = false) {
+    const Inspector &children = first ? self["roots"] : self["children"];
+    if (pos == end) {
+        return (children.entries() == 0);
     }
-    if ((*pos)["roots"].valid() || (*pos)["children"].valid()) {
-        fprintf(stderr, "path too shallow\n");
-        return false;
+    auto needle = *pos++;
+    for (size_t i = 0; i < children.entries(); ++i) {
+        if ((children[i]["name"].asString().make_string() == needle.first) &&
+            (children[i]["count"].asLong() == needle.second) &&
+            (find_path(children[i], pos, end)))
+        {
+            return true;
+        }
     }
-    return true;
+    return false;
+}
+
+bool find_path(const Slime &slime, const std::vector<std::pair<vespalib::string,int64_t>> &path) {
+    return find_path(slime.get(), path.begin(), path.end(), true);
 }
 
 TEST(ExecutionProfilerTest, resolve_names) {
@@ -101,7 +82,7 @@ TEST(ExecutionProfilerTest, empty_report) {
     profiler.report(slime.setObject());
     fprintf(stderr, "%s\n", slime.toString().c_str());
     EXPECT_EQ(slime["roots"].entries(), 0);
-    EXPECT_TRUE(verify_path(slime.get(), {}));
+    EXPECT_TRUE(find_path(slime, {}));
 }
 
 TEST(ExecutionProfilerTest, perform_dummy_profiling) {
@@ -116,14 +97,14 @@ TEST(ExecutionProfilerTest, perform_dummy_profiling) {
     profiler.report(slime.setObject());
     fprintf(stderr, "%s\n", slime.toString().c_str());
     EXPECT_EQ(slime["roots"].entries(), 4);
-    EXPECT_TRUE(verify_path(slime.get(), {{"foo", 3}, {"bar", 3}, {"baz", 6}, {"fox", 18}}));
-    EXPECT_TRUE(verify_path(slime.get(), {{"foo", 3}, {"bar", 3}, {"fox", 6}}));
-    EXPECT_TRUE(verify_path(slime.get(), {{"foo", 3}, {"baz", 3}, {"fox", 9}}));
-    EXPECT_TRUE(verify_path(slime.get(), {{"foo", 3}, {"fox", 3}}));
-    EXPECT_TRUE(verify_path(slime.get(), {{"bar", 3}, {"baz", 6}, {"fox", 18}}));
-    EXPECT_TRUE(verify_path(slime.get(), {{"bar", 3}, {"fox", 6}}));
-    EXPECT_TRUE(verify_path(slime.get(), {{"baz", 3}, {"fox", 9}}));
-    EXPECT_TRUE(verify_path(slime.get(), {{"fox", 3}}));
+    EXPECT_TRUE(find_path(slime, {{"foo", 3}, {"bar", 3}, {"baz", 6}, {"fox", 18}}));
+    EXPECT_TRUE(find_path(slime, {{"foo", 3}, {"bar", 3}, {"fox", 6}}));
+    EXPECT_TRUE(find_path(slime, {{"foo", 3}, {"baz", 3}, {"fox", 9}}));
+    EXPECT_TRUE(find_path(slime, {{"foo", 3}, {"fox", 3}}));
+    EXPECT_TRUE(find_path(slime, {{"bar", 3}, {"baz", 6}, {"fox", 18}}));
+    EXPECT_TRUE(find_path(slime, {{"bar", 3}, {"fox", 6}}));
+    EXPECT_TRUE(find_path(slime, {{"baz", 3}, {"fox", 9}}));
+    EXPECT_TRUE(find_path(slime, {{"fox", 3}}));
 }
 
 TEST(ExecutionProfilerTest, perform_shallow_dummy_profiling) {
@@ -138,14 +119,41 @@ TEST(ExecutionProfilerTest, perform_shallow_dummy_profiling) {
     profiler.report(slime.setObject());
     fprintf(stderr, "%s\n", slime.toString().c_str());
     EXPECT_EQ(slime["roots"].entries(), 4);
-    EXPECT_TRUE(verify_path(slime.get(), {{"foo", 3}, {"bar", 3}}));
-    EXPECT_TRUE(verify_path(slime.get(), {{"foo", 3}, {"bar", 3}}));
-    EXPECT_TRUE(verify_path(slime.get(), {{"foo", 3}, {"baz", 3}}));
-    EXPECT_TRUE(verify_path(slime.get(), {{"foo", 3}, {"fox", 3}}));
-    EXPECT_TRUE(verify_path(slime.get(), {{"bar", 3}, {"baz", 6}}));
-    EXPECT_TRUE(verify_path(slime.get(), {{"bar", 3}, {"fox", 6}}));
-    EXPECT_TRUE(verify_path(slime.get(), {{"baz", 3}, {"fox", 9}}));
-    EXPECT_TRUE(verify_path(slime.get(), {{"fox", 3}}));
+    EXPECT_TRUE(find_path(slime, {{"foo", 3}, {"bar", 3}}));
+    EXPECT_TRUE(find_path(slime, {{"foo", 3}, {"bar", 3}}));
+    EXPECT_TRUE(find_path(slime, {{"foo", 3}, {"baz", 3}}));
+    EXPECT_TRUE(find_path(slime, {{"foo", 3}, {"fox", 3}}));
+    EXPECT_TRUE(find_path(slime, {{"bar", 3}, {"baz", 6}}));
+    EXPECT_TRUE(find_path(slime, {{"bar", 3}, {"fox", 6}}));
+    EXPECT_TRUE(find_path(slime, {{"baz", 3}, {"fox", 9}}));
+    EXPECT_TRUE(find_path(slime, {{"fox", 3}}));
+}
+
+TEST(ExecutionProfilerTest, with_name_mapping) {
+    Profiler profiler(64);
+    for (int i = 0; i < 3; ++i) {
+        foo(profiler);
+        bar(profiler);
+        baz(profiler);
+        fox(profiler);
+    }
+    Slime slime;
+    profiler.report(slime.setObject(), [](const vespalib::string &name)noexcept->vespalib::string {
+                                           if ((name == "foo") || (name == "bar")) {
+                                               return "magic";
+                                           }
+                                           return name;
+                                       });
+    fprintf(stderr, "%s\n", slime.toString().c_str());
+    EXPECT_EQ(slime["roots"].entries(), 4);
+    EXPECT_TRUE(find_path(slime, {{"magic", 3}, {"magic", 3}, {"baz", 6}, {"fox", 18}}));
+    EXPECT_TRUE(find_path(slime, {{"magic", 3}, {"magic", 3}, {"fox", 6}}));
+    EXPECT_TRUE(find_path(slime, {{"magic", 3}, {"baz", 3}, {"fox", 9}}));
+    EXPECT_TRUE(find_path(slime, {{"magic", 3}, {"fox", 3}}));
+    EXPECT_TRUE(find_path(slime, {{"magic", 3}, {"baz", 6}, {"fox", 18}}));
+    EXPECT_TRUE(find_path(slime, {{"magic", 3}, {"fox", 6}}));
+    EXPECT_TRUE(find_path(slime, {{"baz", 3}, {"fox", 9}}));
+    EXPECT_TRUE(find_path(slime, {{"fox", 3}}));
 }
 
 GTEST_MAIN_RUN_ALL_TESTS()
diff --git a/vespalib/src/vespa/vespalib/util/execution_profiler.cpp b/vespalib/src/vespa/vespalib/util/execution_profiler.cpp
index 3a0e4a77ce3..3c56901adb7 100644
--- a/vespalib/src/vespa/vespalib/util/execution_profiler.cpp
+++ b/vespalib/src/vespa/vespalib/util/execution_profiler.cpp
@@ -1,6 +1,7 @@
 // Copyright Yahoo. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
 
 #include "execution_profiler.h"
+#include <vespa/vespalib/stllike/hash_map.h>
 #include <vespa/vespalib/data/slime/slime.h>
 #include <cassert>
 
@@ -14,6 +15,20 @@ double as_ms(duration d) {
 
 }
 
+struct ExecutionProfiler::ReportContext {
+    const ExecutionProfiler::NameMapper &name_mapper;
+    vespalib::hash_map<vespalib::string,vespalib::string> name_cache;
+    ReportContext(const ExecutionProfiler::NameMapper &name_mapper_in, size_t num_names)
+      : name_mapper(name_mapper_in), name_cache(num_names * 2) {}
+    const vespalib::string &resolve_name(const vespalib::string &name) {
+        auto pos = name_cache.find(name);
+        if (pos == name_cache.end()) {
+            pos = name_cache.insert(std::make_pair(name, name_mapper(name))).first;
+        }
+        return pos->second;
+    }
+};
+
 duration
 ExecutionProfiler::get_children_time(const Edges &edges) const
 {
@@ -39,24 +54,24 @@ ExecutionProfiler::get_sorted_children(const Edges &edges) const
 }
 
 void
-ExecutionProfiler::render_node(slime::Cursor &obj, NodeId node) const
+ExecutionProfiler::render_node(slime::Cursor &obj, NodeId node, ReportContext &ctx) const
 {
-    obj.setString("name", _names[_nodes[node].task]);
+    obj.setString("name", ctx.resolve_name(_names[_nodes[node].task]));
     obj.setLong("count", _nodes[node].count);
     obj.setDouble("total_time_ms", as_ms(_nodes[node].total_time));
     if (!_nodes[node].children.empty()) {
         auto children_time = get_children_time(_nodes[node].children);
         obj.setDouble("self_time_ms", as_ms(_nodes[node].total_time - children_time));
-        render_children(obj.setArray("children"), _nodes[node].children);
+        render_children(obj.setArray("children"), _nodes[node].children, ctx);
     }
 }
 
 void
-ExecutionProfiler::render_children(slime::Cursor &arr, const Edges &edges) const
+ExecutionProfiler::render_children(slime::Cursor &arr, const Edges &edges, ReportContext &ctx) const
 {
     auto children = get_sorted_children(edges);
     for (NodeId child: children) {
-        render_node(arr.addObject(), child);
+        render_node(arr.addObject(), child, ctx);
     }
 }
 
@@ -111,11 +126,12 @@ ExecutionProfiler::resolve(const vespalib::string &name)
 }
 
 void
-ExecutionProfiler::report(slime::Cursor &obj) const
+ExecutionProfiler::report(slime::Cursor &obj, const NameMapper &name_mapper) const
 {
+    ReportContext ctx(name_mapper, std::min(_names.size(), _nodes.size()));
     obj.setDouble("total_time_ms", as_ms(get_children_time(_roots)));
     if (!_roots.empty()) {
-        render_children(obj.setArray("roots"), _roots);
+        render_children(obj.setArray("roots"), _roots, ctx);
     }
 }
 
diff --git a/vespalib/src/vespa/vespalib/util/execution_profiler.h b/vespalib/src/vespa/vespalib/util/execution_profiler.h
index 5791c5ec3d7..b5060e9a3c2 100644
--- a/vespalib/src/vespa/vespalib/util/execution_profiler.h
+++ b/vespalib/src/vespa/vespalib/util/execution_profiler.h
@@ -6,6 +6,7 @@
 
 #include <vespa/vespalib/stllike/string.h>
 #include <vespa/vespalib/stllike/hash_map.h>
+#include <functional>
 
 namespace vespalib {
 
@@ -24,6 +25,7 @@ namespace slime { struct Cursor; }
 class ExecutionProfiler {
 public:
     using TaskId = uint32_t;
+    using NameMapper = std::function<vespalib::string(const vespalib::string &)>;
 private:
     using NodeId = uint32_t;
     using Edges = vespalib::hash_map<TaskId, NodeId>;
@@ -44,6 +46,7 @@ private:
         Frame(NodeId node_in) noexcept
           : node(node_in), start(steady_clock::now()) {}
     };
+    struct ReportContext;
 
     size_t _max_depth;
     std::vector<vespalib::string> _names;
@@ -55,8 +58,8 @@ private:
 
     duration get_children_time(const Edges &edges) const;
     std::vector<NodeId> get_sorted_children(const Edges &edges) const;
-    void render_node(slime::Cursor &obj, NodeId node) const;
-    void render_children(slime::Cursor &arr, const Edges &edges) const;
+    void render_node(slime::Cursor &obj, NodeId node, ReportContext &ctx) const;
+    void render_children(slime::Cursor &arr, const Edges &edges, ReportContext &ctx) const;
 
     void track_start(TaskId task);
     void track_complete();
@@ -75,7 +78,7 @@ public:
             track_complete();
         }
     }
-    void report(slime::Cursor &obj) const;
+    void report(slime::Cursor &obj, const NameMapper & = [](const vespalib::string &name) noexcept { return name; }) const;
 };
 
 }