From 47bc33a22152317bfb8e0a9eb9ce0caa9c7f894d Mon Sep 17 00:00:00 2001 From: David Zane <38449481+dzane17@users.noreply.github.com> Date: Tue, 6 Aug 2024 09:33:34 -0700 Subject: [PATCH] Add took time to request nodes stats (#15054) Signed-off-by: David Zane --- CHANGELOG-3.0.md | 1 + .../action/search/SearchRequestStats.java | 31 ++++++++++++++++ .../index/search/stats/SearchStats.java | 24 ++++++++++++- .../search/SearchRequestStatsTests.java | 35 +++++++++++++++++++ 4 files changed, 90 insertions(+), 1 deletion(-) diff --git a/CHANGELOG-3.0.md b/CHANGELOG-3.0.md index 4edde351f5677..29e862e8dc25b 100644 --- a/CHANGELOG-3.0.md +++ b/CHANGELOG-3.0.md @@ -13,6 +13,7 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/), - GHA to verify checklist items completion in PR descriptions ([#10800](https://github.com/opensearch-project/OpenSearch/pull/10800)) - Allow to pass the list settings through environment variables (like [], ["a", "b", "c"], ...) ([#10625](https://github.com/opensearch-project/OpenSearch/pull/10625)) - Views, simplify data access and manipulation by providing a virtual layer over one or more indices ([#11957](https://github.com/opensearch-project/OpenSearch/pull/11957)) +- Add took time to request nodes stats ([#15054](https://github.com/opensearch-project/OpenSearch/pull/15054)) ### Dependencies diff --git a/server/src/main/java/org/opensearch/action/search/SearchRequestStats.java b/server/src/main/java/org/opensearch/action/search/SearchRequestStats.java index 97ef94055faf7..d1d5f568fc09d 100644 --- a/server/src/main/java/org/opensearch/action/search/SearchRequestStats.java +++ b/server/src/main/java/org/opensearch/action/search/SearchRequestStats.java @@ -27,6 +27,7 @@ @PublicApi(since = "2.11.0") public final class SearchRequestStats extends SearchRequestOperationsListener { Map phaseStatsMap = new EnumMap<>(SearchPhaseName.class); + StatsHolder tookStatsHolder; public static final String SEARCH_REQUEST_STATS_ENABLED_KEY = "search.request_stats_enabled"; public static final Setting SEARCH_REQUEST_STATS_ENABLED = Setting.boolSetting( @@ -40,6 +41,7 @@ public final class SearchRequestStats extends SearchRequestOperationsListener { public SearchRequestStats(ClusterSettings clusterSettings) { this.setEnabled(clusterSettings.get(SEARCH_REQUEST_STATS_ENABLED)); clusterSettings.addSettingsUpdateConsumer(SEARCH_REQUEST_STATS_ENABLED, this::setEnabled); + tookStatsHolder = new StatsHolder(); for (SearchPhaseName searchPhaseName : SearchPhaseName.values()) { phaseStatsMap.put(searchPhaseName, new StatsHolder()); } @@ -57,6 +59,18 @@ public long getPhaseMetric(SearchPhaseName searchPhaseName) { return phaseStatsMap.get(searchPhaseName).timing.sum(); } + public long getTookCurrent() { + return tookStatsHolder.current.count(); + } + + public long getTookTotal() { + return tookStatsHolder.total.count(); + } + + public long getTookMetric() { + return tookStatsHolder.timing.sum(); + } + @Override protected void onPhaseStart(SearchPhaseContext context) { phaseStatsMap.get(context.getCurrentPhase().getSearchPhaseName()).current.inc(); @@ -75,6 +89,23 @@ protected void onPhaseFailure(SearchPhaseContext context, Throwable cause) { phaseStatsMap.get(context.getCurrentPhase().getSearchPhaseName()).current.dec(); } + @Override + protected void onRequestStart(SearchRequestContext searchRequestContext) { + tookStatsHolder.current.inc(); + } + + @Override + protected void onRequestEnd(SearchPhaseContext context, SearchRequestContext searchRequestContext) { + tookStatsHolder.current.dec(); + tookStatsHolder.total.inc(); + tookStatsHolder.timing.inc(TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - searchRequestContext.getAbsoluteStartNanos())); + } + + @Override + protected void onRequestFailure(SearchPhaseContext context, SearchRequestContext searchRequestContext) { + tookStatsHolder.current.dec(); + } + /** * Holder of statistics values * diff --git a/server/src/main/java/org/opensearch/index/search/stats/SearchStats.java b/server/src/main/java/org/opensearch/index/search/stats/SearchStats.java index bb61e1afa05f4..d6ea803c9ee13 100644 --- a/server/src/main/java/org/opensearch/index/search/stats/SearchStats.java +++ b/server/src/main/java/org/opensearch/index/search/stats/SearchStats.java @@ -110,7 +110,7 @@ public void writeTo(StreamOutput out) throws IOException { } /** - * Holds requests stats for different phases. + * Holds all requests stats. * * @opensearch.api */ @@ -124,6 +124,7 @@ public Map getRequestStatsHolder() { } RequestStatsLongHolder() { + requestStatsHolder.put(Fields.TOOK, new PhaseStatsLongHolder()); for (SearchPhaseName searchPhaseName : SearchPhaseName.values()) { requestStatsHolder.put(searchPhaseName.getName(), new PhaseStatsLongHolder()); } @@ -512,6 +513,15 @@ public XContentBuilder toXContent(XContentBuilder builder, Params params) throws if (requestStatsLongHolder != null) { builder.startObject(Fields.REQUEST); + PhaseStatsLongHolder tookStatsLongHolder = requestStatsLongHolder.requestStatsHolder.get(Fields.TOOK); + if (tookStatsLongHolder != null) { + builder.startObject(Fields.TOOK); + builder.humanReadableField(Fields.TIME_IN_MILLIS, Fields.TIME, new TimeValue(tookStatsLongHolder.timeInMillis)); + builder.field(Fields.CURRENT, tookStatsLongHolder.current); + builder.field(Fields.TOTAL, tookStatsLongHolder.total); + builder.endObject(); + } + for (SearchPhaseName searchPhaseName : SearchPhaseName.values()) { PhaseStatsLongHolder statsLongHolder = requestStatsLongHolder.requestStatsHolder.get(searchPhaseName.getName()); if (statsLongHolder == null) { @@ -545,6 +555,17 @@ public void setSearchRequestStats(SearchRequestStats searchRequestStats) { totalStats.requestStatsLongHolder = new RequestStatsLongHolder(); } + // Set took stats + totalStats.requestStatsLongHolder.requestStatsHolder.put( + Fields.TOOK, + new PhaseStatsLongHolder( + searchRequestStats.getTookCurrent(), + searchRequestStats.getTookTotal(), + searchRequestStats.getTookMetric() + ) + ); + + // Set phase stats for (SearchPhaseName searchPhaseName : SearchPhaseName.values()) { totalStats.requestStatsLongHolder.requestStatsHolder.put( searchPhaseName.getName(), @@ -678,6 +699,7 @@ static final class Fields { static final String CURRENT = "current"; static final String TOTAL = "total"; static final String SEARCH_IDLE_REACTIVATE_COUNT_TOTAL = "search_idle_reactivate_count_total"; + static final String TOOK = "took"; } diff --git a/server/src/test/java/org/opensearch/action/search/SearchRequestStatsTests.java b/server/src/test/java/org/opensearch/action/search/SearchRequestStatsTests.java index 1af3eb2738a58..3bad3ec3e7d21 100644 --- a/server/src/test/java/org/opensearch/action/search/SearchRequestStatsTests.java +++ b/server/src/test/java/org/opensearch/action/search/SearchRequestStatsTests.java @@ -25,6 +25,41 @@ import static org.mockito.Mockito.when; public class SearchRequestStatsTests extends OpenSearchTestCase { + public void testSearchRequestStats_OnRequestFailure() { + ClusterSettings clusterSettings = new ClusterSettings(Settings.EMPTY, ClusterSettings.BUILT_IN_CLUSTER_SETTINGS); + SearchRequestStats testRequestStats = new SearchRequestStats(clusterSettings); + SearchPhaseContext mockSearchPhaseContext = mock(SearchPhaseContext.class); + SearchRequestContext mockSearchRequestContext = mock(SearchRequestContext.class); + + testRequestStats.onRequestStart(mockSearchRequestContext); + assertEquals(1, testRequestStats.getTookCurrent()); + testRequestStats.onRequestFailure(mockSearchPhaseContext, mockSearchRequestContext); + assertEquals(0, testRequestStats.getTookCurrent()); + assertEquals(0, testRequestStats.getTookTotal()); + } + + public void testSearchRequestStats_OnRequestEnd() { + ClusterSettings clusterSettings = new ClusterSettings(Settings.EMPTY, ClusterSettings.BUILT_IN_CLUSTER_SETTINGS); + SearchRequestStats testRequestStats = new SearchRequestStats(clusterSettings); + SearchPhaseContext mockSearchPhaseContext = mock(SearchPhaseContext.class); + SearchRequestContext mockSearchRequestContext = mock(SearchRequestContext.class); + + // Start request + testRequestStats.onRequestStart(mockSearchRequestContext); + assertEquals(1, testRequestStats.getTookCurrent()); + + // Mock start time + long tookTimeInMillis = randomIntBetween(1, 10); + long startTimeInNanos = System.nanoTime() - TimeUnit.MILLISECONDS.toNanos(tookTimeInMillis); + when(mockSearchRequestContext.getAbsoluteStartNanos()).thenReturn(startTimeInNanos); + + // End request + testRequestStats.onRequestEnd(mockSearchPhaseContext, mockSearchRequestContext); + assertEquals(0, testRequestStats.getTookCurrent()); + assertEquals(1, testRequestStats.getTookTotal()); + assertThat(testRequestStats.getTookMetric(), greaterThanOrEqualTo(tookTimeInMillis)); + } + public void testSearchRequestPhaseFailure() { ClusterSettings clusterSettings = new ClusterSettings(Settings.EMPTY, ClusterSettings.BUILT_IN_CLUSTER_SETTINGS); SearchRequestStats testRequestStats = new SearchRequestStats(clusterSettings);