No throughput metrics available for [bulk]. Likely cause: The benchmark ended already during warmup

Rally version (get with esrally --version):

esrally 1.0.0

Invoked command:

esrally race --pipeline=benchmark-only --target-hosts="/root/.rally/benchmarks/tracks/billions-rally-tracks/jssz_benchmark_scene_1/target_host.json" --offline --track=jssz_benchmark_scene_1 --track-repository=billions-rally-tracks --track-params="/root/.rally/benchmarks/tracks/billions-rally-tracks/jssz_benchmark_scene_1/params/params.json"

Configuration file (located in ~/track.json)):

{% set index_count = 3 %}
{% import "rally.helpers" as rally with context %}
{
  "version": 2,
  "description": "max throughput with {{index_count}} index",
  "indices": [
    {% set comma = joiner() %}
    {% for item in range(index_count) %}
    {{ comma() }}
    {
      "name": "billions-jssz.benchmark.scene1-{{item}}",
      "body": "settings/mapping.json",
      "types": [
        {
          "name": "logs",
          "documents": "{{index_source_file | default('documents.json')}}",
          "document-count": {{ index_document_count | default(1) }},
          "uncompressed-bytes": {{ index_uncompressed_bytes | default(1) }}
        }
      ]
    }
    {% endfor %}
  ],
  "challenges": [
    {{ rally.collect(parts="challenges/just_bulk.json") }}
  ]
}

Configuration file (located in ~/challenges/just_bulk.json)):

{
  "name": "just_bulk",
  "description": "just bulk",
  "default": true,
  "schedule": [
    {
      "operation": {
        "operation-type": "delete-index"
      }
    },
    {
      "operation": {
        "operation-type": "create-index"
      }
    },
    {
      "warmup-time-period": 0,
      "operation": {
        "operation-type": "bulk",
        "bulk-size": {{ bulk_size | default(20000) }}
      },
      "clients": {{ clients | default(97) }}
    }
  ]
}

Configuration file (located in ~/params/params.json)):

{
  "number_of_shards": 1,
  "number_of_replicas": 0,
  "refresh_interval": "30s",
  "sync_interval": "60s",
  "durability": "async",
  "source_enabled": true,
  "index_source_file": "documents.json",
  "index_document_count": 4500000,
  "index_uncompressed_bytes": 13051575427,
  "bulk_size": 20000,
  "clients": 97
}

And i also try:

{
  xxx
  "bulk_size": 20000,
  "clients": 10
}

After run the race, the summary report is:

************************************************************************
****** Use this pipeline only if you are aware of the tradeoffs.  ******
*************************** Watch your step! ***************************
************************************************************************

[INFO] Racing on track [jssz_benchmark_scene_1], challenge [just_bulk] and car ['external'] with version [5.4.3].

[WARNING] merges_total_time is 1520597 ms indicating that the cluster is not in a defined clean state. Recorded index time metrics may be misleading.
[WARNING] indexing_total_time is 58637 ms indicating that the cluster is not in a defined clean state. Recorded index time metrics may be misleading.
[WARNING] refresh_total_time is 160000 ms indicating that the cluster is not in a defined clean state. Recorded index time metrics may be misleading.
[WARNING] flush_total_time is 41 ms indicating that the cluster is not in a defined clean state. Recorded index time metrics may be misleading.
Running delete-index                                                           [100% done]
Running create-index                                                           [100% done]
Running bulk                                                                   [100% done]

------------------------------------------------------
    _______             __   _____
   / ____(_)___  ____ _/ /  / ___/_________  ________
  / /_  / / __ \/ __ `/ /   \__ \/ ___/ __ \/ ___/ _ \
 / __/ / / / / / /_/ / /   ___/ / /__/ /_/ / /  /  __/
/_/   /_/_/ /_/\__,_/_/   /____/\___/\____/_/   \___/
------------------------------------------------------

|   Lap |                         Metric |   Task |       Value |   Unit |
|------:|-------------------------------:|-------:|------------:|-------:|
|   All |            Total indexing time |        |      0.9775 |    min |
|   All |    Min indexing time per shard |        |           0 |    min |
|   All | Median indexing time per shard |        | 0.000783333 |    min |
|   All |    Max indexing time per shard |        |      0.6527 |    min |
|   All |               Total merge time |        |     25.3433 |    min |
|   All |       Min merge time per shard |        |           0 |    min |
|   All |    Median merge time per shard |        |           0 |    min |
|   All |       Max merge time per shard |        |     19.7772 |    min |
|   All |             Total refresh time |        |      2.6671 |    min |
|   All |     Min refresh time per shard |        |           0 |    min |
|   All |  Median refresh time per shard |        |     0.00095 |    min |
|   All |     Max refresh time per shard |        |     1.73317 |    min |
|   All |               Total flush time |        | 0.000683333 |    min |
|   All |       Min flush time per shard |        |           0 |    min |
|   All |    Median flush time per shard |        |           0 |    min |
|   All |       Max flush time per shard |        |      0.0005 |    min |
|   All |             Total Young Gen GC |        |           0 |      s |
|   All |               Total Old Gen GC |        |           0 |      s |
|   All |                     Store size |        |    0.042077 |     GB |
|   All |                  Translog size |        |   0.0629594 |     GB |
|   All |         Heap used for segments |        |    0.213631 |     MB |
|   All |       Heap used for doc values |        |   0.0656433 |     MB |
|   All |            Heap used for terms |        |    0.115535 |     MB |
|   All |            Heap used for norms |        |  0.00115967 |     MB |
|   All |           Heap used for points |        |   0.0222368 |     MB |
|   All |    Heap used for stored fields |        |  0.00905609 |     MB |
|   All |                  Segment count |        |          16 |        |
|   All |                     error rate |   bulk |           0 |      % |

[WARNING] No throughput metrics available for [bulk]. Likely cause: The benchmark ended already during warmup.

After running, the summary report has no throughput, and there is no data inserted into ES.
Is there anything wrong with my configuration?

Hi,

did you already consider the hints I've provided in the related Github ticket?

Daniel

I have rerun with --on-error="abort", but there is no error. And i try the configure(located in ~/params/params.json):

{
  "number_of_shards": 1,
  "number_of_replicas": 0,
  "refresh_interval": "30s",
  "sync_interval": "60s",
  "durability": "async",
  "source_enabled": true,
  "index_source_file": "documents.json",
  "index_document_count": 4500000,
  "index_uncompressed_bytes": 13051575427,
  "bulk_size": 20000,
  "clients": 10
}
{
  ...
  "index_source_file": "test.json",
  "index_document_count": 1000,
  "index_uncompressed_bytes": 2902581,
  "bulk_size": 200,
  "clients": 10
}

however the summary output also has no throughput metrics.

the logs:

2018-09-05 11:05:26,388 ActorAddr-(T|:61145)/PID:181950 esrally.track.loader INFO Reading track specification file [/root/.rally/
benchmarks/tracks/billions-rally-tracks/jssz_benchmark_scene_1/track.json].
2018-09-05 11:05:26,420 ActorAddr-(T|:22554)/PID:181951 esrally.metrics INFO Opening metrics store for trial timestamp=[20180905T
110526Z], track=[jssz_benchmark_scene_1], challenge=[just_bulk], car=[['external']]
2018-09-05 11:05:26,400 ActorAddr-(T|:61145)/PID:181950 esrally.track.loader INFO Final rendered track for '/root/.rally/benchmar
ks/tracks/billions-rally-tracks/jssz_benchmark_scene_1/track.json':
{
... 
}

2018-09-05 11:05:26,474 ActorAddr-(T|:61145)/PID:181950 esrally.actor INFO Capabilities [{'coordinator': True, 'Python Version': (3, 4, 2, 'final', 0), 'Convention Address.IPv4': '127.0.0.1:1900', 'Thespian ActorSystem Version': 2, 'ip': '127.0.0.1', 'Thespian Version': '1536145526336', 'Thespian Generation': (3, 9), 'Thespian Watch Supported': True, 'Thespian ActorSystem Name': 'multiprocTCPBase'}] match requirements [{'coordinator': True}].
2018-09-05 11:05:26,476 ActorAddr-(T|:61145)/PID:181950 esrally.actor INFO Telling driver to start benchmark.
2018-09-05 11:05:26,475 ActorAddr-(T|:22554)/PID:181951 esrally.actor INFO Transitioning from [cluster_started] to [benchmark_starting].
2018-09-05 11:05:26,482 ActorAddr-(T|:61145)/PID:181950 esrally.actor INFO BenchmarkActor received unknown message [<esrally.mechanic.mechanic.BenchmarkStarted object at 0x7fa427dfd828>] (ignoring).
2018-09-05 11:05:26,480 ActorAddr-(T|:22554)/PID:181951 esrally.mechanic.telemetry WARNING merges_total_time is 1964464 ms indica
ting that the cluster is not in a defined clean state. Recorded index time metrics may be misleading.
2018-09-05 11:05:26,480 ActorAddr-(T|:22554)/PID:181951 esrally.mechanic.telemetry WARNING indexing_total_time is 69839 ms indica
ting that the cluster is not in a defined clean state. Recorded index time metrics may be misleading.
2018-09-05 11:05:26,481 ActorAddr-(T|:22554)/PID:181951 esrally.mechanic.telemetry WARNING refresh_total_time is 182961 ms indica
ting that the cluster is not in a defined clean state. Recorded index time metrics may be misleading.
2018-09-05 11:05:26,481 ActorAddr-(T|:22554)/PID:181951 esrally.mechanic.telemetry WARNING flush_total_time is 41 ms indicating t
hat the cluster is not in a defined clean state. Recorded index time metrics may be misleading.
2018-09-05 11:05:26,483 ActorAddr-(T|:2797)/PID:181958 esrally.metrics INFO Creating in-memory metrics store
2018-09-05 11:05:26,484 ActorAddr-(T|:2797)/PID:181958 esrally.metrics INFO Opening metrics store for trial timestamp=[20180905T1
10526Z], track=[jssz_benchmark_scene_1], challenge=[just_bulk], car=[['external']]
2018-09-05 11:05:26,484 ActorAddr-(T|:2797)/PID:181958 esrally.actor INFO Capabilities [{'coordinator': True, 'Python Version': (
3, 4, 2, 'final', 0), 'Convention Address.IPv4': '127.0.0.1:1900', 'Thespian ActorSystem Version': 2, 'ip': '127.0.0.1', 'Thespia
n Version': '1536145526336', 'Thespian Generation': (3, 9), 'Thespian Watch Supported': True, 'Thespian ActorSystem Name': 'multi
procTCPBase'}] match requirements [{'coordinator': True}].
2018-09-05 11:05:26,492 ActorAddr-(T|:56378)/PID:181959 esrally.actor INFO Preparing track [jssz_benchmark_scene_1]
2018-09-05 11:05:26,505 ActorAddr-(T|:2797)/PID:181958 esrally.driver.driver INFO Benchmark is about to start.
2018-09-05 11:05:26,498 ActorAddr-(T|:56378)/PID:181959 esrally.utils.repo INFO Checking out [master] in [/root/.rally/benchmarks
/tracks/billions-rally-tracks] for distribution version [5.4.3].
2018-09-05 11:05:26,505 ActorAddr-(T|:2797)/PID:181958 esrally.driver.driver INFO Benchmark consists of [3] steps executed by (at
 most) [10] clients as specified by the allocation matrix:
[[JoinPoint(0), TaskAllocation [0/1] for delete-index, JoinPoint(1), TaskAllocation [0/1] for create-index, JoinPoint(2), TaskAllocation [0/10] for bulk, JoinPoint(3)], [JoinPoint(0), None, JoinPoint(1), None, JoinPoint(2), TaskAllocation [9/10] for bulk, JoinPoint(3)]]
2018-09-05 11:05:26,506 ActorAddr-(T|:2797)/PID:181958 esrally.driver.driver INFO Allocating load generator [0] on [localhost]
2018-09-05 11:05:26,506 ActorAddr-(T|:2797)/PID:181958 esrally.actor INFO Capabilities [{'coordinator': True, 'Python Version': (3, 4, 2, 'final', 0), 'Convention Address.IPv4': '127.0.0.1:1900', 'Thespian ActorSystem Version': 2, 'ip': '127.0.0.1', 'Thespian Version': '1536145526336', 'Thespian Generation': (3, 9), 'Thespian Watch Supported': True, 'Thespian ActorSystem Name': 'multiprocTCPBase'}] match requirements [{'coordinator': True}].
...

Hi,

is it possible that you retry with a larger document corpus or with only 1 client and a bulk size of - say - 100?

Daniel

I have tryed:

{
  "number_of_shards": 1,
  "number_of_replicas": 0,
  "refresh_interval": "30s",
  "sync_interval": "60s",
  "durability": "async",
  "source_enabled": true,
  "index_source_file": "documents.json",
  "index_document_count": 4500000,
  "index_uncompressed_bytes": 13051575427,
  "bulk_size": 20000,
  "clients": 10
}
{
  "number_of_shards": 1,
  "number_of_replicas": 0,
  "refresh_interval": "30s",
  "sync_interval": "60s",
  "durability": "async",
  "source_enabled": true,
  "index_source_file": "test.json",
  "index_document_count": 1000,
  "index_uncompressed_bytes": 2902581,
  "bulk_size": 200,
  "clients": 10
}
{
  "number_of_shards": 1,
  "number_of_replicas": 0,
  "refresh_interval": "30s",
  "sync_interval": "60s",
  "durability": "async",
  "source_enabled": true,
  "index_source_file": "documents.json",
  "index_document_count": 4500000,
  "index_uncompressed_bytes": 13051575427,
  "bulk_size": 100,
  "clients": 1
}

And this is all logs:

do you think clients, bulk_size, documet size cause this problem??

Hi,

I am really sorry but the logs as they are now are unreadable... . Can you please upload them somewhere (gist, Dropbox, ...) so I can inspect them as text? Thanks.

Daniel

you can see the configure & log file at: https://github.com/cjx-great/RallyQuestions

Hi,

now I saw the problem. You are using the old syntax to specify document corpora. The bulk action looks for a corpora block but did not find any (and we should probably raise an error when this happens). So to make your track work you need to define the document corpus separately. For example:

{
  "version": 2,
  "description": "max throughput with 3 index",
  "indices": [
    {
      "name": "billions-jssz.benchmark.scene1-0",
      "body": "settings/mapping.json",
      "types": [ "logs" ]
    },
    {
      "name": "billions-jssz.benchmark.scene1-1",
      "body": "settings/mapping.json",
      "types": [ "logs" ]
    },
    {
      "name": "billions-jssz.benchmark.scene1-2",
      "body": "settings/mapping.json",
      "types": [ "logs" ]
    }
  ],
  "corpora": [
      {
        "name": "billions-jssz",
        "target-type": "logs",
        "documents": [
          {
            "target-index": "billions-jssz.benchmark.scene1-0",
            "source-file": "documents.json",
            "document-count": 1000,
            "uncompressed-bytes": 39986
          },
          {
            "target-index": "billions-jssz.benchmark.scene1-1",
            "source-file": "documents.json",
            "document-count": 1000,
            "uncompressed-bytes": 39986
          },
          {
            "target-index": "billions-jssz.benchmark.scene1-2",
            "source-file": "documents.json",
            "document-count": 1000,
            "uncompressed-bytes": 39986
          }
        ]
      }
  ],
  "challenges": [
    {
      "name": "just_bulk",
      "description": "just bulk",
      "default": true,
      "schedule": [
        {
          "operation": {
            "operation-type": "delete-index"
          }
        },
        {
          "operation": {
            "operation-type": "create-index"
          }
        },
        {
          "warmup-time-period": 0,
          "operation": {
            "operation-type": "bulk",
            "bulk-size": 100
          },
          "clients": 1
        }
      ]
    }
  ]
}

Note how we defined a new corpora block and simplified the indices block in the example above.

We've changed this already in Rally 0.9.0. See also the migration guide to Rally 0.9.0.

By the way, with regards to setting up your benchmarks correctly, I recommend our blog article Seven Tips for Better Elasticsearch Benchmarks as a starting point.

Daniel

oh, I have understanded how it is. Thank you for your help!!!:+1:
I will try this

Hi,

meanwhile I have raised https://github.com/elastic/rally/issues/568 so in a future version Rally will report an error when this happens. Also thank you for your continued feedback via Github issues or here on Discuss. That's how we can improve the product. :slight_smile:

Daniel

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