diff options
11 files changed, 92 insertions, 28 deletions
diff --git a/searchcore/src/tests/proton/matching/match_phase_limiter/match_phase_limiter_test.cpp b/searchcore/src/tests/proton/matching/match_phase_limiter/match_phase_limiter_test.cpp index dd2396e5f34..45ac0a8f924 100644 --- a/searchcore/src/tests/proton/matching/match_phase_limiter/match_phase_limiter_test.cpp +++ b/searchcore/src/tests/proton/matching/match_phase_limiter/match_phase_limiter_test.cpp @@ -318,7 +318,7 @@ TEST("require that the match phase limiter is able to pre-limit the query") { EXPECT_TRUE(limiter.is_enabled()); EXPECT_EQUAL(12u, limiter.sample_hits_per_thread(10)); RelativeTime clock(std::make_unique<CountingClock>(vespalib::count_ns(10000000s), 1700000L)); - Trace trace(clock, 7, 0); + Trace trace(clock, 7); trace.start(4, false); SearchIterator::UP search = limiter.maybe_limit(prepare(new MockSearch("search")), 0.1, 100000, trace.maybeCreateCursor(7, "limit")); limiter.updateDocIdSpaceEstimate(1000, 9000); diff --git a/searchcore/src/vespa/searchcore/proton/matching/match_master.cpp b/searchcore/src/vespa/searchcore/proton/matching/match_master.cpp index 063666e9cad..4450b34296b 100644 --- a/searchcore/src/vespa/searchcore/proton/matching/match_master.cpp +++ b/searchcore/src/vespa/searchcore/proton/matching/match_master.cpp @@ -105,11 +105,10 @@ MatchMaster::match(search::engine::Trace & trace, std::vector<MatchThread::UP> threadState; for (size_t i = 0; i < threadBundle.size(); ++i) { IMatchLoopCommunicator &com = (i == 0) - ? static_cast<IMatchLoopCommunicator&>(timedCommunicator) - : static_cast<IMatchLoopCommunicator&>(communicator); + ? static_cast<IMatchLoopCommunicator&>(timedCommunicator) + : static_cast<IMatchLoopCommunicator&>(communicator); threadState.emplace_back(std::make_unique<MatchThread>(i, threadBundle.size(), params, mtf, com, *scheduler, - resultProcessor, mergeDirector, distributionKey, - trace.getRelativeTime(), trace.getLevel(), trace.getProfileDepth())); + resultProcessor, mergeDirector, distributionKey, trace)); } resultProcessor.prepareThreadContextCreation(threadBundle.size()); threadBundle.run(threadState); diff --git a/searchcore/src/vespa/searchcore/proton/matching/match_thread.cpp b/searchcore/src/vespa/searchcore/proton/matching/match_thread.cpp index 0463568213b..620e4f1ff1d 100644 --- a/searchcore/src/vespa/searchcore/proton/matching/match_thread.cpp +++ b/searchcore/src/vespa/searchcore/proton/matching/match_thread.cpp @@ -403,10 +403,8 @@ MatchThread::MatchThread(size_t thread_id_in, ResultProcessor &rp, vespalib::DualMergeDirector &md, uint32_t distributionKey, - const RelativeTime & relativeTime, - uint32_t traceLevel, - uint32_t profileDepth) : - thread_id(thread_id_in), + const Trace &parent_trace) + : thread_id(thread_id_in), num_threads(num_threads_in), matchParams(mp), matchToolsFactory(mtf), @@ -422,16 +420,25 @@ MatchThread::MatchThread(size_t thread_id_in, match_time_s(0.0), wait_time_s(0.0), match_with_ranking(mtf.has_first_phase_rank() && mp.save_rank_scores()), - trace(std::make_unique<Trace>(relativeTime, traceLevel, profileDepth)), + trace(std::make_unique<Trace>(parent_trace.getRelativeTime(), parent_trace.getLevel())), match_profiler(), first_phase_profiler(), second_phase_profiler(), my_issues() { - if ((traceLevel > 0) && (profileDepth > 0)) { - match_profiler = std::make_unique<vespalib::ExecutionProfiler>(profileDepth); - first_phase_profiler = std::make_unique<vespalib::ExecutionProfiler>(profileDepth); - second_phase_profiler = std::make_unique<vespalib::ExecutionProfiler>(profileDepth); + trace->match_profile_depth(parent_trace.match_profile_depth()); + trace->first_phase_profile_depth(parent_trace.first_phase_profile_depth()); + trace->second_phase_profile_depth(parent_trace.second_phase_profile_depth()); + if (trace->getLevel() > 0) { + if (int32_t depth = trace->match_profile_depth(); depth != 0) { + match_profiler = std::make_unique<vespalib::ExecutionProfiler>(depth); + } + if (int32_t depth = trace->first_phase_profile_depth(); depth != 0) { + first_phase_profiler = std::make_unique<vespalib::ExecutionProfiler>(depth); + } + if (int32_t depth = trace->second_phase_profile_depth(); depth != 0) { + second_phase_profiler = std::make_unique<vespalib::ExecutionProfiler>(depth); + } } } diff --git a/searchcore/src/vespa/searchcore/proton/matching/match_thread.h b/searchcore/src/vespa/searchcore/proton/matching/match_thread.h index 3f97bfe4f08..757caae0e75 100644 --- a/searchcore/src/vespa/searchcore/proton/matching/match_thread.h +++ b/searchcore/src/vespa/searchcore/proton/matching/match_thread.h @@ -131,9 +131,7 @@ public: ResultProcessor &rp, vespalib::DualMergeDirector &md, uint32_t distributionKey, - const RelativeTime & relativeTime, - uint32_t traceLevel, - uint32_t profileDepth); + const Trace &parent_trace); void run() override; const MatchingStats::Partition &get_thread_stats() const { return thread_stats; } double get_match_time() const { return match_time_s; } diff --git a/searchcore/src/vespa/searchcore/proton/matching/match_tools.cpp b/searchcore/src/vespa/searchcore/proton/matching/match_tools.cpp index 8894473dcc7..86b21445919 100644 --- a/searchcore/src/vespa/searchcore/proton/matching/match_tools.cpp +++ b/searchcore/src/vespa/searchcore/proton/matching/match_tools.cpp @@ -186,7 +186,10 @@ MatchToolsFactory(QueryLimiter & queryLimiter, _diversityParams(), _valid(false) { - search::engine::Trace trace(root_trace.getRelativeTime(), root_trace.getLevel(), root_trace.getProfileDepth()); + search::engine::Trace trace(root_trace.getRelativeTime(), root_trace.getLevel()); + trace.match_profile_depth(root_trace.match_profile_depth()); + trace.first_phase_profile_depth(root_trace.first_phase_profile_depth()); + trace.second_phase_profile_depth(root_trace.second_phase_profile_depth()); trace.addEvent(4, "Start query setup"); _query.setWhiteListBlueprint(metaStore.createWhiteListBlueprint()); trace.addEvent(5, "Deserialize and build query tree"); diff --git a/searchlib/src/protobuf/search_protocol.proto b/searchlib/src/protobuf/search_protocol.proto index 1be68abad04..916788796b8 100644 --- a/searchlib/src/protobuf/search_protocol.proto +++ b/searchlib/src/protobuf/search_protocol.proto @@ -24,7 +24,18 @@ message SearchRequest { bytes grouping_blob = 15; // serialized opaquely like now, to be changed later string geo_location = 16; // to be moved into query_tree bytes query_tree_blob = 17; // serialized opaquely like now, to be changed later - int32 profile_depth = 18; + int32 profile_depth = 18; // new meaning: default ProfilingParams.depth + Profiling profiling = 19; +} + +message Profiling { + ProfilingParams match = 1; + ProfilingParams first_phase = 2; + ProfilingParams second_phase = 3; +} + +message ProfilingParams { + int32 depth = 1; } message TensorProperty { diff --git a/searchlib/src/tests/engine/proto_converter/proto_converter_test.cpp b/searchlib/src/tests/engine/proto_converter/proto_converter_test.cpp index bd40a4566cd..ad20684bd04 100644 --- a/searchlib/src/tests/engine/proto_converter/proto_converter_test.cpp +++ b/searchlib/src/tests/engine/proto_converter/proto_converter_test.cpp @@ -69,7 +69,28 @@ TEST_F(SearchRequestTest, require_that_trace_level_is_converted) { TEST_F(SearchRequestTest, require_that_profile_depth_is_converted) { proto.set_profile_depth(7); convert(); - EXPECT_EQ(request.trace().getProfileDepth(), 7); + EXPECT_EQ(request.trace().match_profile_depth(), 7); + EXPECT_EQ(request.trace().first_phase_profile_depth(), 7); + EXPECT_EQ(request.trace().second_phase_profile_depth(), 7); +} + +TEST_F(SearchRequestTest, require_that_profiling_params_are_converted) { + proto.mutable_profiling()->mutable_match()->set_depth(4); + proto.mutable_profiling()->mutable_first_phase()->set_depth(5); + proto.mutable_profiling()->mutable_second_phase()->set_depth(6); + convert(); + EXPECT_EQ(request.trace().match_profile_depth(), 4); + EXPECT_EQ(request.trace().first_phase_profile_depth(), 5); + EXPECT_EQ(request.trace().second_phase_profile_depth(), 6); +} + +TEST_F(SearchRequestTest, require_that_profile_depth_is_fallback) { + proto.mutable_profiling()->mutable_first_phase()->set_depth(5); + proto.set_profile_depth(7); + convert(); + EXPECT_EQ(request.trace().match_profile_depth(), 7); + EXPECT_EQ(request.trace().first_phase_profile_depth(), 5); + EXPECT_EQ(request.trace().second_phase_profile_depth(), 7); } TEST_F(SearchRequestTest, require_that_sorting_is_converted) { diff --git a/searchlib/src/vespa/searchlib/engine/proto_converter.cpp b/searchlib/src/vespa/searchlib/engine/proto_converter.cpp index 842ced502c6..ae00889850b 100644 --- a/searchlib/src/vespa/searchlib/engine/proto_converter.cpp +++ b/searchlib/src/vespa/searchlib/engine/proto_converter.cpp @@ -69,7 +69,18 @@ ProtoConverter::search_request_from_proto(const ProtoSearchRequest &proto, Searc request.maxhits = proto.hits(); request.setTimeout(1ms * proto.timeout()); request.trace().setLevel(proto.trace_level()); - request.trace().setProfileDepth(proto.profile_depth()); + if (int32_t value = proto.profile_depth(); value != 0) { + request.trace().profile_depth(value); + } + if (int32_t value = proto.profiling().match().depth(); value != 0) { + request.trace().match_profile_depth(value); + } + if (int32_t value = proto.profiling().first_phase().depth(); value != 0) { + request.trace().first_phase_profile_depth(value); + } + if (int32_t value = proto.profiling().second_phase().depth(); value != 0) { + request.trace().second_phase_profile_depth(value); + } request.sortSpec = make_sort_spec(proto.sorting()); request.sessionId.assign(proto.session_key().begin(), proto.session_key().end()); request.propertiesMap.lookupCreate(MapNames::MATCH).add("documentdb.searchdoctype", proto.document_type()); diff --git a/searchlib/src/vespa/searchlib/engine/request.cpp b/searchlib/src/vespa/searchlib/engine/request.cpp index d88d3740f07..e4ab55fcacf 100644 --- a/searchlib/src/vespa/searchlib/engine/request.cpp +++ b/searchlib/src/vespa/searchlib/engine/request.cpp @@ -16,7 +16,7 @@ Request::Request(RelativeTime relativeTime, uint32_t reservePropMaps) location(), propertiesMap(reservePropMaps), stackDump(), - _trace(_relativeTime, 0, 0) + _trace(_relativeTime, 0) { } diff --git a/searchlib/src/vespa/searchlib/engine/trace.cpp b/searchlib/src/vespa/searchlib/engine/trace.cpp index 649823e7ec1..27e652db651 100644 --- a/searchlib/src/vespa/searchlib/engine/trace.cpp +++ b/searchlib/src/vespa/searchlib/engine/trace.cpp @@ -26,13 +26,15 @@ Trace::constructTraces() const { _traces = & root().setArray("traces"); } -Trace::Trace(const RelativeTime & relativeTime, uint32_t level, uint32_t profileDepth) +Trace::Trace(const RelativeTime & relativeTime, uint32_t level) : _trace(), _root(nullptr), _traces(nullptr), _relativeTime(relativeTime), _level(level), - _profileDepth(profileDepth) + _match_profile_depth(0), + _first_phase_profile_depth(0), + _second_phase_profile_depth(0) { } diff --git a/searchlib/src/vespa/searchlib/engine/trace.h b/searchlib/src/vespa/searchlib/engine/trace.h index a9107787bc5..a76313ca5a5 100644 --- a/searchlib/src/vespa/searchlib/engine/trace.h +++ b/searchlib/src/vespa/searchlib/engine/trace.h @@ -54,7 +54,7 @@ class Trace { public: using Cursor = vespalib::slime::Cursor; - Trace(const RelativeTime & relativeTime, uint32_t traceLevel, uint32_t profileDepth); + Trace(const RelativeTime & relativeTime, uint32_t traceLevel); ~Trace(); /** @@ -90,8 +90,18 @@ public: bool shouldTrace(uint32_t level) const { return level <= _level; } uint32_t getLevel() const { return _level; } Trace & setLevel(uint32_t level) { _level = level; return *this; } - Trace & setProfileDepth(uint32_t depth) { _profileDepth = depth; return *this; } - uint32_t getProfileDepth() const { return _profileDepth; } + Trace &match_profile_depth(int32_t depth) { _match_profile_depth = depth; return *this; } + Trace &first_phase_profile_depth(int32_t depth) { _first_phase_profile_depth = depth; return *this; } + Trace &second_phase_profile_depth(int32_t depth) { _second_phase_profile_depth = depth; return *this; } + Trace &profile_depth(int32_t depth) { + match_profile_depth(depth); + first_phase_profile_depth(depth); + second_phase_profile_depth(depth); + return *this; + } + int32_t match_profile_depth() const { return _match_profile_depth; } + int32_t first_phase_profile_depth() const { return _first_phase_profile_depth; } + int32_t second_phase_profile_depth() const { return _second_phase_profile_depth; } const RelativeTime & getRelativeTime() const { return _relativeTime; } private: vespalib::Slime & slime() const { @@ -120,7 +130,9 @@ private: mutable Cursor * _traces; const RelativeTime & _relativeTime; uint32_t _level; - uint32_t _profileDepth; + int32_t _match_profile_depth; + int32_t _first_phase_profile_depth; + int32_t _second_phase_profile_depth; }; } |