100 prosent error rate on Rally when using parent-child

Elastic Stack Elasticsearch
1

I have an index with an parent child structure. When I try to run a "race" with it in esrally I get 100 percent error rate. As shown bellow:

Metric Task Value Unit
Cumulative indexing time of primary shards 0 min
Min cumulative indexing time across primary shards 0 min
Median cumulative indexing time across primary shards 0 min
Max cumulative indexing time across primary shards 0 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 min
Cumulative refresh count of primary shards 2
Min cumulative refresh time across primary shards 0 min
Median cumulative refresh time across primary shards 0 min
Max cumulative refresh time across primary shards 0 min
Cumulative flush time of primary shards 0 min
Cumulative flush count of primary shards 0
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 min
Total Young Gen GC time 0 s
Total Young Gen GC count 0
Total Old Gen GC time 0 s
Total Old Gen GC count 0
Store size 1.93715e-07 GB
Translog size 5.12227e-08 GB
Heap used for segments 0 MB
Heap used for doc values 0 MB
Heap used for terms 0 MB
Heap used for norms 0 MB
Heap used for points 0 MB
Heap used for stored fields 0 MB
Segment count 0
Min Throughput bulk 24.64 docs/s
Median Throughput bulk 24.64 docs/s
Max Throughput bulk 24.64 docs/s
50th percentile latency bulk 28.8184 ms
100th percentile latency bulk 116.64 ms
50th percentile service time bulk 28.8184 ms
100th percentile service time bulk 116.64 ms
error rate bulk 100 %

I am suppose to specify the number of parent documents If i understood esrally documentation. That might be the issue, but how do I do that?

2

Is there anything in the Rally logs? What does your track look like?

1 Like
3

the error logs are endless but they start like this:

2020-08-21 11:21:25,396 ActorAddr-(T|:35829)/PID:245165 esrally.actor INFO Worker[1] is exiting due to ActorExitRequest.
2020-08-21 11:21:25,389 ActorAddr-(T|:39661)/PID:244562 esrally.metrics INFO Closing metrics store.
2020-08-21 11:21:25,389 ActorAddr-(T|:39661)/PID:244562 esrally.actor INFO Asking mechanic to stop the engine.
2020-08-21 11:21:25,411 ActorAddr-(T|:36487)/PID:245167 esrally.actor INFO Worker[3] has received ActorExitRequest.
2020-08-21 11:21:25,409 ActorAddr-(T|:44839)/PID:245166 esrally.actor INFO Worker[2] has received ActorExitRequest.
2020-08-21 11:21:25,412 ActorAddr-(T|:33861)/PID:244974 esrally.actor INFO Worker [0] has exited.
2020-08-21 11:21:25,417 ActorAddr-(T|:36487)/PID:245167 esrally.actor INFO Worker[3] is exiting due to ActorExitRequest.
2020-08-21 11:21:25,409 ActorAddr-(T|:44839)/PID:245166 esrally.actor INFO Worker[2] is exiting due to ActorExitRequest.
2020-08-21 11:21:25,413 ActorAddr-(T|:33861)/PID:244974 esrally.actor INFO Worker [1] has exited.
2020-08-21 11:21:25,422 ActorAddr-(T|:39661)/PID:244562 esrally.actor INFO BenchmarkActor received unknown message [ChildActorExited:ActorAddr-(T|:33861)] (ignoring).
2020-08-21 11:21:25,414 ActorAddr-(T|:33861)/PID:244974 esrally.actor INFO Worker [2] has exited.
2020-08-21 11:21:25,418 ActorAddr-(T|:33861)/PID:244974 esrally.actor INFO Worker [3] has exited.
2020-08-21 11:21:25,437 ActorAddr-(T|:39661)/PID:244562 esrally.actor INFO BenchmarkActor received unknown message [ChildActorExited:ActorAddr-(T|:33861)] (ignoring).
2020-08-21 11:21:25,391 ActorAddr-(T|:33525)/PID:244586 esrally.mechanic.launcher INFO Shutting down [1] nodes on this host.
2020-08-21 11:21:26,947 ActorAddr-(T|:39661)/PID:244562 esrally.actor INFO Mechanic has stopped engine successfully.
2020-08-21 11:21:26,948 -not-actor-/PID:244549 esrally.racecontrol INFO Benchmark has finished successfully.
2020-08-21 11:21:26,948 -not-actor-/PID:244549 esrally.racecontrol INFO Telling benchmark actor to exit.
2020-08-21 11:21:26,858 ActorAddr-(T|:33525)/PID:244586 esrally.mechanic.launcher INFO Done shutting down node [rally-node-0] in [0.3] s.
2020-08-21 11:21:26,949 ActorAddr-(T|:41597)/PID:244585 esrally.actor INFO mechanic.Dispatcher#receiveMessage unrecognized(msg = [<class 'thespian.actors.ChildActorExited'>] sender = [ActorAddr-(T|:33525)])
2020-08-21 11:21:26,949 ActorAddr-(T|:39661)/PID:244562 esrally.actor INFO BenchmarkActor received unknown message [ActorExitRequest] (ignoring).
2020-08-21 11:21:26,859 ActorAddr-(T|:33525)/PID:244586 esrally.metrics INFO Creating file race store
2020-08-21 11:21:26,951 ActorAddr-(T|:42171)/PID:244563 esrally.actor INFO MechanicActor#receiveMessage unrecognized(msg = [<class 'thespian.actors.ActorExitRequest'>] sender = [ActorAddr-(T|:39661)])
2020-08-21 11:21:26,862 ActorAddr-(T|:33525)/PID:244586 esrally.metrics INFO Creating no-op results store
2020-08-21 11:21:26,951 ActorAddr-(T|:41597)/PID:244585 esrally.actor INFO mechanic.Dispatcher#receiveMessage unrecognized(msg = [<class 'thespian.actors.ActorExitRequest'>] sender = [ActorAddr-(T|:42171)])
2020-08-21 11:21:26,862 ActorAddr-(T|:33525)/PID:244586 esrally.metrics INFO Closing metrics store.
2020-08-21 11:21:26,862 ActorAddr-(T|:33525)/PID:244586 esrally.mechanic.provisioner INFO Wiping benchmark candidate installation at [/home/user/.rally/benchmarks/races/380458b4-827e-430e-b505-77d2de11198f/rally-node-0/install/elasticsearch-8.0.0-SNAPSHOT].
2020-08-21 11:21:26,953 ActorAddr-(T|:42171)/PID:244563 esrally.actor INFO Child actor exited while engine is stopping or stopped: [ChildActorExited:ActorAddr-(T|:41597)]
2020-08-21 11:21:26,957 ActorAddr-(T|:39661)/PID:244562 esrally.actor INFO BenchmarkActor received unknown message [ChildActorExited:ActorAddr-(T|:42171)] (ignoring).
2020-08-21 11:21:29,952 -not-actor-/PID:244549 esrally.rally INFO Attempting to shutdown internal actor system.
2020-08-21 11:21:29,953 -not-actor-/PID:244561 root INFO ActorSystem Logging Shutdown
2020-08-21 11:21:29,974 -not-actor-/PID:244560 root INFO ---- Actor System shutdown
2020-08-21 11:21:29,975 -not-actor-/PID:244549 esrally.rally INFO Actor system is still running. Waiting...
2020-08-21 11:21:30,977 -not-actor-/PID:244549 esrally.rally INFO Shutdown completed.
2020-08-21 11:25:38,734 -not-actor-/PID:252347 esrally.rally INFO Race id [6633d84e-8850-4e1f-ba07-a060ea37ae67]
2020-08-21 11:25:38,734 -not-actor-/PID:252347 esrally.rally INFO OS [uname_result(system='Linux', node='Machine', release='5.4.0-42-generic', version='#46-Ubuntu SMP Fri Jul 10 00:24:02 UTC 2020', machine='x86_64', processor='x86_64')]
2020-08-21 11:25:38,734 -not-actor-/PID:252347 esrally.rally INFO Python [namespace(_multiarch='x86_64-linux-gnu', cache_tag='cpython-38', hexversion=50856688, name='cpython', version=sys.version_info(major=3, minor=8, micro=2, releaselevel='final', serial=0))]
2020-08-21 11:25:38,735 -not-actor-/PID:252347 esrally.rally INFO Rally version [2.0.1]
2020-08-21 11:25:38,735 -not-actor-/PID:252347 esrally.utils.net INFO Connecting directly to the Internet (no proxy support).
2020-08-21 11:25:39,76 -not-actor-/PID:252347 esrally.rally INFO Detected a working Internet connection.
2020-08-21 11:25:39,115 -not-actor-/PID:252347 esrally.rally INFO Actor system already running locally? [False]
2020-08-21 11:25:39,115 -not-actor-/PID:252347 esrally.actor INFO Starting actor system with system base [multiprocTCPBase] and capabilities [{'coordinator': True, 'ip': '127.0.0.1', 'Convention Address.IPv4': '127.0.0.1:1900'}].
2020-08-21 11:25:39,131 -not-actor-/PID:252407 root INFO ++++ Actor System gen (3, 10) started, admin @ ActorAddr-(T|:1900)
2020-08-21 11:25:39,142 -not-actor-/PID:252347 esrally.racecontrol INFO User specified no pipeline. Automatically derived pipeline [from-sources].
2020-08-21 11:25:39,142 -not-actor-/PID:252347 esrally.racecontrol INFO Setting default host to [127.0.0.1:39200]
2020-08-21 11:25:39,143 -not-actor-/PID:252347 esrally.actor INFO Joining already running actor system with system base [multiprocTCPBase].
2020-08-21 11:25:39,145 ActorAddr-(T|:1900)/PID:252407 esrally.actor INFO Capabilities [{'coordinator': True, 'ip': '127.0.0.1', 'Convention Address.IPv4': '127.0.0.1:1900', 'Thespian ActorSystem Name': 'multiprocTCPBase', 'Thespian ActorSystem Version': 2, 'Thespian Watch Supported': True, 'Python Version': (3, 8, 2, 'final', 0), 'Thespian Generation': (3, 10), 'Thespian Version': '1598009139124'}] match requirements [{'coordinator': True}].
2020-08-21 11:25:39,154 ActorAddr-(T|:33391)/PID:252414 esrally.track.loader INFO Reading track specification file [/home/user/tracks/acme/track.json].
2020-08-21 11:25:39,169 ActorAddr-(T|:33391)/PID:252414 esrally.track.loader INFO Final rendered track for '/home/user/tracks/acme/track.json' has been written to '/tmp/tmp_lngg0vv.json'.
2020-08-21 11:25:39,174 ActorAddr-(T|:33391)/PID:252414 esrally.track.loader INFO Loading template [definition for index test_child_parent3 in test_child_parent3.json].
2020-08-21 11:25:39,180 ActorAddr-(T|:33391)/PID:252414 esrally.metrics INFO Creating in-memory metrics store
2020-08-21 11:25:39,180 ActorAddr-(T|:33391)/PID:252414 esrally.metrics INFO Opening metrics store for race timestamp=[20200821T112538Z], track=[acme], challenge=[default], car=[['defaults']]
2020-08-21 11:25:39,180 ActorAddr-(T|:33391)/PID:252414 esrally.metrics INFO Creating file race store
2020-08-21 11:25:39,181 ActorAddr-(T|:33391)/PID:252414 esrally.actor INFO Asking mechanic to start the engine.
2020-08-21 11:25:39,181 ActorAddr-(T|:33391)/PID:252414 esrally.actor INFO Capabilities [{'coordinator': True, 'ip': '127.0.0.1', 'Convention Address.IPv4': '127.0.0.1:1900', 'Thespian ActorSystem Name': 'multiprocTCPBase', 'Thespian ActorSystem Version': 2, 'Thespian Watch Supported': True, 'Python Version': (3, 8, 2, 'final', 0), 'Thespian Generation': (3, 10), 'Thespian Version': '1598009139124'}] match requirements [{'coordinator': True}].
2020-08-21 11:25:39,191 ActorAddr-(T|:46623)/PID:252419 esrally.actor INFO Received signal from race control to start engine.
2020-08-21 11:25:39,800 ActorAddr-(T|:46623)/PID:252419 esrally.utils.repo INFO Checking out [master] in [/home/user/.rally/benchmarks/teams/default] for distribution version [None].
2020-08-21 11:25:39,810 ActorAddr-(T|:46623)/PID:252419 esrally.utils.process INFO Switched to branch 'master'
Your branch is up to date with 'origin/master'.

2020-08-21 11:25:39,811 ActorAddr-(T|:46623)/PID:252419 esrally.utils.repo INFO Rebasing on [master] in [/home/user/.rally/benchmarks/teams/default] for distribution version [None].
2020-08-21 11:25:39,828 ActorAddr-(T|:46623)/PID:252419 esrally.utils.process INFO Already on 'master'
Your branch is up to date with 'origin/master'.

2020-08-21 11:25:39,840 ActorAddr-(T|:46623)/PID:252419 esrally.utils.process INFO Current branch master is up to date.

2020-08-21 11:25:39,851 ActorAddr-(T|:46623)/PID:252419 esrally.actor INFO Cluster consisting of [{'host': '127.0.0.1', 'port': 39200}] will be provisioned by Rally.
2020-08-21 11:25:39,852 ActorAddr-(T|:46623)/PID:252419 esrally.actor INFO Capabilities [{'coordinator': True, 'ip': '127.0.0.1', 'Convention Address.IPv4': '127.0.0.1:1900', 'Thespian ActorSystem Name': 'multiprocTCPBase', 'Thespian ActorSystem Version': 2, 'Thespian Watch Supported': True, 'Python Version': (3, 8, 2, 'final', 0), 'Thespian Generation': (3, 10), 'Thespian Version': '1598009139124'}] match requirements [{}].
2020-08-21 11:25:39,870 ActorAddr-(T|:43915)/PID:252455 esrally.actor INFO Capabilities [{'coordinator': True, 'ip': '127.0.0.1', 'Convention Address.IPv4': '127.0.0.1:1900', 'Thespian ActorSystem Name': 'multiprocTCPBase', 'Thespian ActorSystem Version': 2, 'Thespian Watch Supported': True, 'Python Version': (3, 8, 2, 'final', 0), 'Thespian Generation': (3, 10), 'Thespian Version': '1598009139124'}] match requirements [{'coordinator': True}].
2020-08-21 11:25:39,881 ActorAddr-(T|:46071)/PID:252456 esrally.actor INFO Starting node(s) [0] on [127.0.0.1].
2020-08-21 11:25:39,883 ActorAddr-(T|:46071)/PID:252456 esrally.metrics INFO Opening metrics store for race timestamp=[20200821T112538Z], track=[acme], challenge=[default], car=[['defaults']]
2020-08-21 11:25:40,490 ActorAddr-(T|:46071)/PID:252456 esrally.utils.repo INFO Checking out revision [2f0d5d9] in [/home/user/.rally/benchmarks/teams/default].
2020-08-21 11:25:40,501 ActorAddr-(T|:46071)/PID:252456 esrally.utils.process INFO Note: switching to '2f0d5d9'.

And this is the track:

{% import "rally.helpers" as rally with context %}
{
  "version": 2,
  "description": "Tracker-generated track for acme",
  "indices": [
    {
      "name": "test_child_parent3",
      "body": "test_child_parent3.json"
    }
  ],
  "corpora": [
    {
      "name": "test_child_parent3",
      "documents": [
        {
          "target-index": "test_child_parent3",
          "source-file": "test_child_parent3-documents.json.bz2",
          "document-count": 83,
          "compressed-bytes": 19400,
          "uncompressed-bytes": 77458
        }
      ]
    }
  ],
  "schedule": [
    {
      "operation": "delete-index"
    },
    {
      "operation": {
        "operation-type": "create-index",
        "settings": {{index_settings | default({}) | tojson}}
      }
    },
    {
      "operation": {
        "operation-type": "cluster-health",
        "index": "test_child_parent3",
        "request-params": {
          "wait_for_status": "{{cluster_health | default('green')}}",
          "wait_for_no_relocating_shards": "true"
        }
      }
    },
    {
      "operation": {
        "operation-type": "bulk",
        "bulk-size": {{bulk_size | default(5000)}},
        "ingest-percentage": {{ingest_percentage | default(100)}}
      },
      "clients": {{bulk_indexing_clients | default(8)}}
    }
  ]
}
4

Your corpora only contains 83 documents which will not even fill one bulk request. The issue is therefore that the track finishes before warmup is completed which leaves no requests to be measured.

1 Like
5

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