Cluster is not in a defined clean state while using the Elasticsearch setup by Rally

I got that message

[WARNING] indexing_total_time is 3941 ms indicating that the cluster is not in a defined clean state. Recorded index time metrics may be misleading.

While running

esrally race --distribution-version=7.17.4 --track-path=~/.rally/tracks/syslog_all --car=defaults,basic-license --kill-running-processes

I'm using the Elasticsearch setup by Rally so I can't really restart my node.
Any idea how to get back to a clean state?

This is surprising. Is there an Elasticsearch process running when Rally is done? Is the 3941ms figure increasing with each new run? Can you please share the logs for a given run?

In order:

  1. [WARNING] indexing_total_time is 3200 ms ...
  2. [WARNING] indexing_total_time is 3862 ms ...
  3. [WARNING] indexing_total_time is 3222 ms ...

200 last line of rally.log after running said command line three time:

2022-06-13 12:16:15,793 ActorAddr-(T|:35829)/PID:19587 esrally.actor INFO Worker[0] is continuing its work at task index [0] on [55971.968713], that is in [0:00:00.988378].
2022-06-13 12:16:16,783 ActorAddr-(T|:35829)/PID:19587 esrally.actor INFO Worker[0] is executing tasks at index [1].
2022-06-13 12:16:16,785 ActorAddr-(T|:35829)/PID:19587 esrally.client INFO Creating ES client connected to [{'host': '127.0.0.1', 'port': 39200}] with options [{'timeout': 60, 'max_connections': 256}]
2022-06-13 12:16:16,786 ActorAddr-(T|:35829)/PID:19587 esrally.client INFO SSL support: off
2022-06-13 12:16:16,786 ActorAddr-(T|:35829)/PID:19587 esrally.client INFO HTTP basic authentication: off
2022-06-13 12:16:16,786 ActorAddr-(T|:35829)/PID:19587 esrally.client INFO HTTP compression: off
2022-06-13 12:16:16,790 ActorAddr-(T|:43697)/PID:19246 esrally.mechanic.mechanic INFO Resetting relative time of system metrics store.
2022-06-13 12:16:16,792 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Task assertions enabled: False
2022-06-13 12:16:16,793 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Choosing [unthrottled] for [delete-index].
2022-06-13 12:16:16,793 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Creating iteration-count based schedule with [None] distribution for [delete-index] with [0] warmup iterations and [1] iterations.
2022-06-13 12:16:16,793 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO iteration-count-based schedule will determine when the schedule for [delete-index] terminates.
2022-06-13 12:16:16,926 -not-actor-/PID:19587 elasticsearch WARNING GET http://127.0.0.1:39200/syslog-mcs-2022.03.09 [status:404 request:0.010s]
2022-06-13 12:16:16,930 -not-actor-/PID:19587 elasticsearch WARNING GET http://127.0.0.1:39200/syslog-mcs-2022.03.10 [status:404 request:0.004s]
2022-06-13 12:16:16,935 -not-actor-/PID:19587 elasticsearch WARNING GET http://127.0.0.1:39200/syslog-mcs-2022.05.09 [status:404 request:0.004s]
2022-06-13 12:16:16,942 -not-actor-/PID:19587 elasticsearch WARNING GET http://127.0.0.1:39200/syslog-mcs-2022.05.10 [status:404 request:0.007s]
2022-06-13 12:16:16,947 -not-actor-/PID:19587 elasticsearch WARNING GET http://127.0.0.1:39200/syslog-mcs-2022.05.11 [status:404 request:0.005s]
2022-06-13 12:16:16,954 -not-actor-/PID:19587 elasticsearch WARNING GET http://127.0.0.1:39200/syslog-mcs-2022.05.12 [status:404 request:0.007s]
2022-06-13 12:16:16,957 -not-actor-/PID:19587 elasticsearch WARNING GET http://127.0.0.1:39200/syslog-mcs-2022.05.13 [status:404 request:0.003s]
2022-06-13 12:16:16,962 -not-actor-/PID:19587 elasticsearch WARNING GET http://127.0.0.1:39200/syslog-mcs-2022.05.16 [status:404 request:0.004s]
2022-06-13 12:16:16,967 -not-actor-/PID:19587 elasticsearch WARNING GET http://127.0.0.1:39200/syslog-mcs-2022.05.17 [status:404 request:0.005s]
2022-06-13 12:16:16,972 -not-actor-/PID:19587 elasticsearch WARNING GET http://127.0.0.1:39200/syslog-mcs-2022.05.18 [status:404 request:0.005s]
2022-06-13 12:16:16,979 -not-actor-/PID:19587 elasticsearch WARNING GET http://127.0.0.1:39200/syslog-mcs-2022.05.19 [status:404 request:0.007s]
2022-06-13 12:16:17,40 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Total run duration: 0.246149 seconds.
2022-06-13 12:16:17,40 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Total time to shutdown asyncgens: 0.000336 seconds.
2022-06-13 12:16:17,40 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Total time to close transports: -0.000311 seconds.
2022-06-13 12:16:21,792 ActorAddr-(T|:35829)/PID:19587 esrally.actor INFO Worker[0] is ready for the next task.
2022-06-13 12:16:21,794 ActorAddr-(T|:35829)/PID:19587 esrally.actor INFO Worker[0] reached join point at index [2].
2022-06-13 12:16:21,799 ActorAddr-(T|:33753)/PID:19544 esrally.driver.driver INFO [1/1] workers reached join point [1/3].
2022-06-13 12:16:21,803 ActorAddr-(T|:34875)/PID:19224 esrally.racecontrol INFO Task has finished.
2022-06-13 12:16:21,803 ActorAddr-(T|:34875)/PID:19224 esrally.racecontrol INFO Bulk adding request metrics to metrics store.
2022-06-13 12:16:21,799 ActorAddr-(T|:33753)/PID:19544 esrally.driver.driver INFO All workers completed their tasks until join point [1/3].
2022-06-13 12:16:21,810 ActorAddr-(T|:35829)/PID:19587 esrally.actor INFO Worker[0] is continuing its work at task index [2] on [55977.990222], that is in [0:00:00.992803].
2022-06-13 12:16:21,807 ActorAddr-(T|:33753)/PID:19544 esrally.driver.driver INFO Scheduling next task for worker id [0] at their timestamp [55977.990222] (master timestamp [55977.994021])
2022-06-13 12:16:22,804 ActorAddr-(T|:35829)/PID:19587 esrally.actor INFO Worker[0] is executing tasks at index [3].
2022-06-13 12:16:22,810 ActorAddr-(T|:43697)/PID:19246 esrally.mechanic.mechanic INFO Resetting relative time of system metrics store.
2022-06-13 12:16:22,806 ActorAddr-(T|:35829)/PID:19587 esrally.client INFO Creating ES client connected to [{'host': '127.0.0.1', 'port': 39200}] with options [{'timeout': 60, 'max_connections': 256}]
2022-06-13 12:16:22,806 ActorAddr-(T|:35829)/PID:19587 esrally.client INFO SSL support: off
2022-06-13 12:16:22,806 ActorAddr-(T|:35829)/PID:19587 esrally.client INFO HTTP basic authentication: off
2022-06-13 12:16:22,807 ActorAddr-(T|:35829)/PID:19587 esrally.client INFO HTTP compression: off
2022-06-13 12:16:22,807 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Task assertions enabled: False
2022-06-13 12:16:22,807 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Choosing [unthrottled] for [create-index].
2022-06-13 12:16:22,807 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Creating iteration-count based schedule with [None] distribution for [create-index] with [0] warmup iterations and [1] iterations.
2022-06-13 12:16:22,807 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO iteration-count-based schedule will determine when the schedule for [create-index] terminates.
2022-06-13 12:16:24,471 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Total run duration: 1.663113 seconds.
2022-06-13 12:16:24,471 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Total time to shutdown asyncgens: 0.000282 seconds.
2022-06-13 12:16:24,471 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Total time to close transports: -0.000297 seconds.
2022-06-13 12:16:27,806 ActorAddr-(T|:35829)/PID:19587 esrally.actor INFO Worker[0] is ready for the next task.
2022-06-13 12:16:27,806 ActorAddr-(T|:35829)/PID:19587 esrally.actor INFO Worker[0] reached join point at index [4].
2022-06-13 12:16:27,809 ActorAddr-(T|:33753)/PID:19544 esrally.driver.driver INFO [1/1] workers reached join point [2/3].
2022-06-13 12:16:27,811 ActorAddr-(T|:34875)/PID:19224 esrally.racecontrol INFO Task has finished.
2022-06-13 12:16:27,811 ActorAddr-(T|:34875)/PID:19224 esrally.racecontrol INFO Bulk adding request metrics to metrics store.
2022-06-13 12:16:27,816 ActorAddr-(T|:35829)/PID:19587 esrally.actor INFO Worker[0] is continuing its work at task index [4] on [55983.998199], that is in [0:00:00.995205].
2022-06-13 12:16:27,809 ActorAddr-(T|:33753)/PID:19544 esrally.driver.driver INFO All workers completed their tasks until join point [2/3].
2022-06-13 12:16:27,814 ActorAddr-(T|:33753)/PID:19544 esrally.driver.driver INFO Scheduling next task for worker id [0] at their timestamp [55983.998199] (master timestamp [55984.000823])
2022-06-13 12:16:28,812 ActorAddr-(T|:35829)/PID:19587 esrally.actor INFO Worker[0] is executing tasks at index [5].
2022-06-13 12:16:28,818 ActorAddr-(T|:43697)/PID:19246 esrally.mechanic.mechanic INFO Resetting relative time of system metrics store.
2022-06-13 12:16:28,813 ActorAddr-(T|:35829)/PID:19587 esrally.client INFO Creating ES client connected to [{'host': '127.0.0.1', 'port': 39200}] with options [{'timeout': 60, 'max_connections': 256}]
2022-06-13 12:16:28,813 ActorAddr-(T|:35829)/PID:19587 esrally.client INFO SSL support: off
2022-06-13 12:16:28,813 ActorAddr-(T|:35829)/PID:19587 esrally.client INFO HTTP basic authentication: off
2022-06-13 12:16:28,813 ActorAddr-(T|:35829)/PID:19587 esrally.client INFO HTTP compression: off
2022-06-13 12:16:28,814 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Task assertions enabled: False
2022-06-13 12:16:28,814 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Choosing [unthrottled] for [bulk].
2022-06-13 12:16:28,814 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Creating time-period based schedule with [None] distribution for [bulk] with a warmup period of [0] seconds and a time period of [None] seconds.
2022-06-13 12:16:28,814 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Parameter source will determine when the schedule for [bulk] terminates.
2022-06-13 12:16:28,815 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Task-relative clients at index [0-0] will bulk index [209966] docs starting from line offset [0] for [syslog-mcs-2022.03.09/None] from corpus [syslog-mcs-2022.03.09].
2022-06-13 12:16:28,815 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Task-relative clients at index [0-0] will bulk index [218114] docs starting from line offset [0] for [syslog-mcs-2022.03.10/None] from corpus [syslog-mcs-2022.03.10].
2022-06-13 12:16:28,815 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Task-relative clients at index [0-0] will bulk index [17593] docs starting from line offset [0] for [syslog-mcs-2022.05.09/None] from corpus [syslog-mcs-2022.05.09].
2022-06-13 12:16:28,815 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Task-relative clients at index [0-0] will bulk index [22826] docs starting from line offset [0] for [syslog-mcs-2022.05.10/None] from corpus [syslog-mcs-2022.05.10].
2022-06-13 12:16:28,815 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Task-relative clients at index [0-0] will bulk index [33390] docs starting from line offset [0] for [syslog-mcs-2022.05.11/None] from corpus [syslog-mcs-2022.05.11].
2022-06-13 12:16:28,815 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Task-relative clients at index [0-0] will bulk index [45239] docs starting from line offset [0] for [syslog-mcs-2022.05.12/None] from corpus [syslog-mcs-2022.05.12].
2022-06-13 12:16:28,815 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Task-relative clients at index [0-0] will bulk index [16746] docs starting from line offset [0] for [syslog-mcs-2022.05.13/None] from corpus [syslog-mcs-2022.05.13].
2022-06-13 12:16:28,816 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Task-relative clients at index [0-0] will bulk index [20187] docs starting from line offset [0] for [syslog-mcs-2022.05.16/None] from corpus [syslog-mcs-2022.05.16].
2022-06-13 12:16:28,816 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Task-relative clients at index [0-0] will bulk index [6036] docs starting from line offset [0] for [syslog-mcs-2022.05.17/None] from corpus [syslog-mcs-2022.05.17].
2022-06-13 12:16:28,816 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Task-relative clients at index [0-0] will bulk index [28663] docs starting from line offset [0] for [syslog-mcs-2022.05.18/None] from corpus [syslog-mcs-2022.05.18].
2022-06-13 12:16:28,816 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Task-relative clients at index [0-0] will bulk index [46065] docs starting from line offset [0] for [syslog-mcs-2022.05.19/None] from corpus [syslog-mcs-2022.05.19].
2022-06-13 12:16:28,816 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Will read [209966] lines from [/home/bastien/.rally/tracks/syslog_all/syslog-mcs-2022.03.09-documents.json] starting from line [0] with bulk size [250].
2022-06-13 12:17:40,133 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Will read [218114] lines from [/home/bastien/.rally/tracks/syslog_all/syslog-mcs-2022.03.10-documents.json] starting from line [0] with bulk size [250].
2022-06-13 12:18:32,67 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Will read [17593] lines from [/home/bastien/.rally/tracks/syslog_all/syslog-mcs-2022.05.09-documents.json] starting from line [0] with bulk size [250].
2022-06-13 12:18:36,260 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Will read [22826] lines from [/home/bastien/.rally/tracks/syslog_all/syslog-mcs-2022.05.10-documents.json] starting from line [0] with bulk size [250].
2022-06-13 12:18:41,545 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Will read [33390] lines from [/home/bastien/.rally/tracks/syslog_all/syslog-mcs-2022.05.11-documents.json] starting from line [0] with bulk size [250].
2022-06-13 12:18:53,907 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Will read [45239] lines from [/home/bastien/.rally/tracks/syslog_all/syslog-mcs-2022.05.12-documents.json] starting from line [0] with bulk size [250].
2022-06-13 12:19:03,583 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Will read [16746] lines from [/home/bastien/.rally/tracks/syslog_all/syslog-mcs-2022.05.13-documents.json] starting from line [0] with bulk size [250].
2022-06-13 12:19:07,285 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Will read [20187] lines from [/home/bastien/.rally/tracks/syslog_all/syslog-mcs-2022.05.16-documents.json] starting from line [0] with bulk size [250].
2022-06-13 12:19:11,946 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Will read [6036] lines from [/home/bastien/.rally/tracks/syslog_all/syslog-mcs-2022.05.17-documents.json] starting from line [0] with bulk size [250].
2022-06-13 12:19:13,401 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Will read [28663] lines from [/home/bastien/.rally/tracks/syslog_all/syslog-mcs-2022.05.18-documents.json] starting from line [0] with bulk size [250].
2022-06-13 12:19:20,383 ActorAddr-(T|:35829)/PID:19587 esrally.track.params INFO Will read [46065] lines from [/home/bastien/.rally/tracks/syslog_all/syslog-mcs-2022.05.19-documents.json] starting from line [0] with bulk size [250].
2022-06-13 12:19:35,129 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Total run duration: 186.314498 seconds.
2022-06-13 12:19:35,130 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Total time to shutdown asyncgens: 0.000777 seconds.
2022-06-13 12:19:35,132 ActorAddr-(T|:35829)/PID:19587 esrally.driver.driver INFO Total time to close transports: -0.002107 seconds.
2022-06-13 12:19:38,958 ActorAddr-(T|:35829)/PID:19587 esrally.actor INFO Worker[0] is ready for the next task.
2022-06-13 12:19:38,959 ActorAddr-(T|:35829)/PID:19587 esrally.actor INFO Worker[0] reached join point at index [6].
2022-06-13 12:19:38,961 ActorAddr-(T|:33753)/PID:19544 esrally.driver.driver INFO [1/1] workers reached join point [3/3].
2022-06-13 12:19:40,20 ActorAddr-(T|:34875)/PID:19224 esrally.racecontrol INFO Benchmark is complete.
2022-06-13 12:19:38,962 ActorAddr-(T|:33753)/PID:19544 esrally.driver.driver INFO All workers completed their tasks until join point [3/3].
2022-06-13 12:19:39,15 ActorAddr-(T|:33753)/PID:19544 esrally.telemetry INFO Gathering index stats for all primaries on benchmark stop.
2022-06-13 12:19:39,975 ActorAddr-(T|:33753)/PID:19544 esrally.telemetry INFO Gathering Ingest Pipeline stats at benchmark end
2022-06-13 12:19:39,979 ActorAddr-(T|:33753)/PID:19544 esrally.driver.driver INFO All steps completed.
2022-06-13 12:19:40,18 ActorAddr-(T|:33753)/PID:19544 esrally.metrics INFO Closing metrics store.
2022-06-13 12:19:40,228 ActorAddr-(T|:33753)/PID:19544 esrally.actor INFO Main driver received ActorExitRequest and will terminate all load generators.
2022-06-13 12:19:40,229 ActorAddr-(T|:35829)/PID:19587 esrally.actor INFO Worker[0] has received ActorExitRequest.
2022-06-13 12:19:40,230 ActorAddr-(T|:35829)/PID:19587 esrally.actor INFO Worker[0] is exiting due to ActorExitRequest.
2022-06-13 12:19:40,234 ActorAddr-(T|:33753)/PID:19544 esrally.actor INFO Worker [0] has exited.
2022-06-13 12:19:40,241 ActorAddr-(T|:35911)/PID:19225 esrally.actor INFO Transitioning from [cluster_started] to [cluster_stopping].
2022-06-13 12:19:40,242 ActorAddr-(T|:43697)/PID:19246 esrally.mechanic.mechanic INFO Stopping nodes [rally-node-0].
2022-06-13 12:19:40,20 ActorAddr-(T|:34875)/PID:19224 esrally.racecontrol INFO Bulk adding request metrics to metrics store.
2022-06-13 12:19:40,219 ActorAddr-(T|:34875)/PID:19224 esrally.metrics INFO Creating no-op results store
2022-06-13 12:19:40,220 ActorAddr-(T|:34875)/PID:19224 esrally.reporter INFO 
------------------------------------------------------
    _______             __   _____
   / ____(_)___  ____ _/ /  / ___/_________  ________
  / /_  / / __ \/ __ `/ /   \__ \/ ___/ __ \/ ___/ _ \
 / __/ / / / / / /_/ / /   ___/ / /__/ /_/ / /  /  __/
/_/   /_/_/ /_/\__,_/_/   /____/\___/\____/_/   \___/
------------------------------------------------------
            
2022-06-13 12:19:40,227 ActorAddr-(T|:34875)/PID:19224 esrally.reporter INFO |                                                         Metric |   Task |         Value |   Unit |
|---------------------------------------------------------------:|-------:|--------------:|-------:|
|                     Cumulative indexing time of primary shards |        |    1.6528     |    min |
|             Min cumulative indexing time across primary shards |        |    0.0126     |    min |
|          Median cumulative indexing time across primary shards |        |    0.0557     |    min |
|             Max cumulative indexing time across primary shards |        |    0.65365    |    min |
|            Cumulative indexing throttle time of primary shards |        |    0          |    min |
|    Min cumulative indexing throttle time across primary shards |        |    0          |    min |
| Median cumulative indexing throttle time across primary shards |        |    0          |    min |
|    Max cumulative indexing throttle time across primary shards |        |    0          |    min |
|                        Cumulative merge time of primary shards |        |    0          |    min |
|                       Cumulative merge count of primary shards |        |    0          |        |
|                Min cumulative merge time across primary shards |        |    0          |    min |
|             Median cumulative merge time across primary shards |        |    0          |    min |
|                Max cumulative merge time across primary shards |        |    0          |    min |
|               Cumulative merge throttle time of primary shards |        |    0          |    min |
|       Min cumulative merge throttle time across primary shards |        |    0          |    min |
|    Median cumulative merge throttle time across primary shards |        |    0          |    min |
|       Max cumulative merge throttle time across primary shards |        |    0          |    min |
|                      Cumulative refresh time of primary shards |        |    0.629917   |    min |
|                     Cumulative refresh count of primary shards |        |   52          |        |
|              Min cumulative refresh time across primary shards |        |    0.0044     |    min |
|           Median cumulative refresh time across primary shards |        |    0.016875   |    min |
|              Max cumulative refresh time across primary shards |        |    0.251083   |    min |
|                        Cumulative flush time of primary shards |        |    0.0032     |    min |
|                       Cumulative flush count of primary shards |        |    3          |        |
|                Min cumulative flush time across primary shards |        |    0          |    min |
|             Median cumulative flush time across primary shards |        |    0          |    min |
|                Max cumulative flush time across primary shards |        |    0.0032     |    min |
|                                        Total Young Gen GC time |        |    4.077      |      s |
|                                       Total Young Gen GC count |        |  494          |        |
|                                          Total Old Gen GC time |        |    0.151      |      s |
|                                         Total Old Gen GC count |        |    1          |        |
|                                                     Store size |        |    0.14078    |     GB |
|                                                  Translog size |        |    0.742289   |     GB |
|                                         Heap used for segments |        |    0.130554   |     MB |
|                                       Heap used for doc values |        |    0.00869751 |     MB |
|                                            Heap used for terms |        |    0.101013   |     MB |
|                                            Heap used for norms |        |    0.00909424 |     MB |
|                                           Heap used for points |        |    0          |     MB |
|                                    Heap used for stored fields |        |    0.0117493  |     MB |
|                                                  Segment count |        |   24          |        |
|                                    Total Ingest Pipeline count |        |    0          |        |
|                                     Total Ingest Pipeline time |        |    0          |      s |
|                                   Total Ingest Pipeline failed |        |    0          |        |
|                                                 Min Throughput |   bulk |  369.07       | docs/s |
|                                                Mean Throughput |   bulk | 3056.06       | docs/s |
|                                              Median Throughput |   bulk | 3258.14       | docs/s |
|                                                 Max Throughput |   bulk | 3606.65       | docs/s |
|                                        50th percentile latency |   bulk |   32.2581     |     ms |
|                                        90th percentile latency |   bulk |   73.9509     |     ms |
|                                        99th percentile latency |   bulk |  102.021      |     ms |
|                                      99.9th percentile latency |   bulk |  261.435      |     ms |
|                                       100th percentile latency |   bulk | 6413.95       |     ms |
|                                   50th percentile service time |   bulk |   32.2581     |     ms |
|                                   90th percentile service time |   bulk |   73.9509     |     ms |
|                                   99th percentile service time |   bulk |  102.021      |     ms |
|                                 99.9th percentile service time |   bulk |  261.435      |     ms |
|                                  100th percentile service time |   bulk | 6413.95       |     ms |
|                                                     error rate |   bulk |    0          |      % |

2022-06-13 12:19:40,227 ActorAddr-(T|:34875)/PID:19224 esrally.metrics INFO Closing metrics store.
2022-06-13 12:19:40,240 ActorAddr-(T|:34875)/PID:19224 esrally.actor INFO Asking mechanic to stop the engine.
2022-06-13 12:19:40,256 ActorAddr-(T|:34875)/PID:19224 esrally.actor INFO BenchmarkActor received unknown message [ChildActorExited:ActorAddr-(T|:33753)] (ignoring).
2022-06-13 12:19:40,266 ActorAddr-(T|:34875)/PID:19224 esrally.actor INFO BenchmarkActor received unknown message [ChildActorExited:ActorAddr-(T|:33753)] (ignoring).
2022-06-13 12:19:42,381 ActorAddr-(T|:34875)/PID:19224 esrally.actor INFO Mechanic has stopped engine successfully.
2022-06-13 12:19:42,382 -not-actor-/PID:19217 esrally.racecontrol INFO Benchmark has finished successfully.
2022-06-13 12:19:42,383 -not-actor-/PID:19217 esrally.racecontrol INFO Telling benchmark actor to exit.
2022-06-13 12:19:42,383 ActorAddr-(T|:34875)/PID:19224 esrally.actor INFO BenchmarkActor received unknown message [ActorExitRequest] (ignoring).
2022-06-13 12:19:42,385 ActorAddr-(T|:35911)/PID:19225 esrally.actor INFO MechanicActor#receiveMessage unrecognized(msg = [<class 'thespian.actors.ActorExitRequest'>] sender = [ActorAddr-(T|:34875)])
2022-06-13 12:19:42,387 ActorAddr-(T|:40547)/PID:19245 esrally.actor INFO mechanic.Dispatcher#receiveMessage unrecognized(msg = [<class 'thespian.actors.ActorExitRequest'>] sender = [ActorAddr-(T|:35911)])
2022-06-13 12:19:42,390 ActorAddr-(T|:40547)/PID:19245 esrally.actor INFO mechanic.Dispatcher#receiveMessage unrecognized(msg = [<class 'thespian.actors.ChildActorExited'>] sender = [ActorAddr-(T|:43697)])
2022-06-13 12:19:42,391 ActorAddr-(T|:35911)/PID:19225 esrally.actor INFO Child actor exited while engine is stopping or stopped: [ChildActorExited:ActorAddr-(T|:40547)]
2022-06-13 12:19:42,394 ActorAddr-(T|:34875)/PID:19224 esrally.actor INFO BenchmarkActor received unknown message [ChildActorExited:ActorAddr-(T|:35911)] (ignoring).
2022-06-13 12:19:40,242 ActorAddr-(T|:43697)/PID:19246 esrally.mechanic.launcher INFO Shutting down [1] nodes on this host.
2022-06-13 12:19:42,302 ActorAddr-(T|:43697)/PID:19246 esrally.mechanic.launcher INFO Done shutting down node [rally-node-0] in [0.9] s.
2022-06-13 12:19:42,315 ActorAddr-(T|:43697)/PID:19246 esrally.metrics INFO Creating file race store
2022-06-13 12:19:42,322 ActorAddr-(T|:43697)/PID:19246 esrally.metrics INFO Creating no-op results store
2022-06-13 12:19:42,322 ActorAddr-(T|:43697)/PID:19246 esrally.metrics INFO Closing metrics store.
2022-06-13 12:19:42,322 ActorAddr-(T|:43697)/PID:19246 esrally.mechanic.provisioner INFO Wiping benchmark candidate installation at [/home/bastien/.rally/benchmarks/races/4920a563-baf7-4978-a9f2-83f2c16b2f4c/rally-node-0/install/elasticsearch-7.17.4].
2022-06-13 12:19:45,386 -not-actor-/PID:19217 esrally.rally INFO Attempting to shutdown internal actor system.
2022-06-13 12:19:45,394 -not-actor-/PID:19223 root INFO ActorSystem Logging Shutdown
2022-06-13 12:19:45,413 -not-actor-/PID:19217 esrally.rally INFO Actor system is still running. Waiting...
2022-06-13 12:19:45,413 -not-actor-/PID:19222 root INFO ---- Actor System shutdown
2022-06-13 12:19:46,415 -not-actor-/PID:19217 esrally.rally INFO Shutdown completed.

Restarting my machine (Debian VM) temporaly resolved the problem.

It's really weird because restarting doesn't always work.

Also deleting 7.17.4 file in the .rally folder then reinstall it when starting the race didn't work either.

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.