From 425d8f6e8828f944607807d192aa7a98a45672f3 Mon Sep 17 00:00:00 2001 From: Daniel Mitterdorfer Date: Tue, 5 Dec 2017 15:03:00 +0100 Subject: [PATCH] Record indexing throttle time Closes #376 --- docs/metrics.rst | 1 + docs/summary_report.rst | 6 ++++++ esrally/mechanic/telemetry.py | 1 + esrally/reporter.py | 5 +++++ 4 files changed, 13 insertions(+) diff --git a/docs/metrics.rst b/docs/metrics.rst index d5f9fd67a..9eb93ab45 100644 --- a/docs/metrics.rst +++ b/docs/metrics.rst @@ -139,6 +139,7 @@ Rally stores the following metrics: * ``merges_total_time``: Total runtime of merges as reported by the indices stats API. Note that this is not Wall clock time (i.e. if M merge threads ran for N minutes, we will report M * N minutes, not N minutes). * ``merges_total_throttled_time``: Total time within merges have been throttled as reported by the indices stats API. Note that this is not Wall clock time. * ``indexing_total_time``: Total time used for indexing as reported by the indices stats API. Note that this is not Wall clock time. +* ``indexing_throttle_time``: Total time that indexing has been throttled as reported by the indices stats API. Note that this is not Wall clock time. * ``refresh_total_time``: Total time used for index refresh as reported by the indices stats API. Note that this is not Wall clock time. * ``flush_total_time``: Total time used for index flush as reported by the indices stats API. Note that this is not Wall clock time. * ``final_index_size_bytes``: Final resulting index size after the benchmark. diff --git a/docs/summary_report.rst b/docs/summary_report.rst index 95356703d..e1edb1409 100644 --- a/docs/summary_report.rst +++ b/docs/summary_report.rst @@ -9,6 +9,12 @@ Indexing time * **Definition**: Total time used for indexing as reported by the indices stats API. Note that this is not Wall clock time (i.e. if M indexing threads ran for N minutes, we will report M * N minutes, not N minutes). * **Corresponding metrics key**: ``indexing_total_time`` +Indexing throttle time +---------------------- + +* **Definition**: Total time that indexing has been throttled as reported by the indices stats API. Note that this is not Wall clock time (i.e. if M indexing threads ran for N minutes, we will report M * N minutes, not N minutes). +* **Corresponding metrics key**: ``indexing_throttle_time`` + Merge time ---------- diff --git a/esrally/mechanic/telemetry.py b/esrally/mechanic/telemetry.py index 48eb1fabd..d706da2de 100644 --- a/esrally/mechanic/telemetry.py +++ b/esrally/mechanic/telemetry.py @@ -708,6 +708,7 @@ def index_times(self, p): "merges_total_time": self.extract_value(p, ["merges", "total_time_in_millis"], default_value=0), "merges_total_throttled_time": self.extract_value(p, ["merges", "total_throttled_time_in_millis"], default_value=0), "indexing_total_time": self.extract_value(p, ["indexing", "index_time_in_millis"], default_value=0), + "indexing_throttle_time": self.extract_value(p, ["indexing", "throttle_time_in_millis"], default_value=0), "refresh_total_time": self.extract_value(p, ["refresh", "total_time_in_millis"], default_value=0), "flush_total_time": self.extract_value(p, ["flush", "total_time_in_millis"], default_value=0) } diff --git a/esrally/reporter.py b/esrally/reporter.py index 8e5803950..968ad06aa 100644 --- a/esrally/reporter.py +++ b/esrally/reporter.py @@ -128,6 +128,7 @@ def __call__(self): logger.debug("Gathering indexing metrics.") result.total_time = self.sum("indexing_total_time") + result.indexing_throttle_time = self.sum("indexing_throttle_time") result.merge_time = self.sum("merges_total_time") result.refresh_time = self.sum("refresh_total_time") result.flush_time = self.sum("flush_total_time") @@ -224,6 +225,7 @@ class Stats: def __init__(self, d=None): self.op_metrics = self.v(d, "op_metrics", default=[]) self.total_time = self.v(d, "total_time") + self.indexing_throttle_time = self.v(d, "indexing_throttle_time") self.merge_time = self.v(d, "merge_time") self.refresh_time = self.v(d, "refresh_time") self.flush_time = self.v(d, "flush_time") @@ -434,6 +436,7 @@ def report_total_times(self, stats): unit = "min" return self.join( self.line("Indexing time", "", stats.total_time, unit, convert.ms_to_minutes), + self.line("Indexing throttle time", "", stats.indexing_throttle_time, unit, convert.ms_to_minutes), self.line("Merge time", "", stats.merge_time, unit, convert.ms_to_minutes), self.line("Refresh time", "", stats.refresh_time, unit, convert.ms_to_minutes), self.line("Flush time", "", stats.flush_time, unit, convert.ms_to_minutes), @@ -634,6 +637,8 @@ def report_total_times(self, baseline_stats, contender_stats): return self.join( self.line("Indexing time", baseline_stats.total_time, contender_stats.total_time, "", "min", treat_increase_as_improvement=False, formatter=convert.ms_to_minutes), + self.line("Indexing throttle time", baseline_stats.indexing_throttle_time, contender_stats.indexing_throttle_time, "", "min", + treat_increase_as_improvement=False, formatter=convert.ms_to_minutes), self.line("Merge time", baseline_stats.merge_time, contender_stats.merge_time, "", "min", treat_increase_as_improvement=False, formatter=convert.ms_to_minutes), self.line("Refresh time", baseline_stats.refresh_time, contender_stats.refresh_time, "", "min",