ESRALLY : CREATE/DELETE operations fail 100% everytime

Elastic Stack Elasticsearch
,
1

I have created a custom track with 2 documents just to debug this use case. I am running this on a remote target index deployed on AWS.

I am trying to debug why my create/delete operations always fail with 100%. I cannot seem to find the root cause. I can perform bulk, cluster-health and search operations as intended, only the create/delete operations that are failing.

concerned track operations -

  "indices": [
    {
      "name": "esrally-2-documents",
      "body": "esrally-2-documents.json"
    }
  ],
.......
"schedule": [
    {
      "operation" : {
        "name": "delete-esrally-2-documents",
        "operation-type": "delete-index",
        "index": "esrally-2-documents"
      }
    },
    {
      "operation": {
        "name": "create-esrally-2-documents",
        "operation-type": "create-index",
        "settings": {
        "index.number_of_shards": 1
        }
      }
    }, ...

Error I am getting when running rally inside docker with --on-error=abort flag.

Running delete-esrally-2-documents                                     [  0% done]
[INFO] Racing on track [esrally-docs-2] and car ['external'] with version [7.10.2].

[ERROR] Cannot race. Error in load generator [0]
	Cannot run task [delete-esrally-2-documents]: Request returned an error. Error type: transport, Description: b'{"Message":"Your request: \'/_cluster/settings\' payload is not allowed."}' ({'Message': "Your request: '/_cluster/settings' payload is not allowed."})

Full error log -

2021-08-01 18:53:35,754 ActorAddr-(T|:37860)/PID:31 esrally.actor DEBUG Worker[0] is at task index [1].
2021-08-01 18:53:35,754 ActorAddr-(T|:37860)/PID:31 esrally.actor INFO Worker[0] is executing tasks at index [1].
2021-08-01 18:53:35,757 ActorAddr-(T|:37860)/PID:31 esrally.client INFO Creating ES client connected to [{'host': '<target-ES-cluster>', 'port': 443}] with options [{'timeout': 60, 'use_ssl': True, 'max_connections': 256}]
2021-08-01 18:53:35,758 ActorAddr-(T|:37860)/PID:31 esrally.client INFO SSL support: on
2021-08-01 18:53:35,766 ActorAddr-(T|:37860)/PID:31 esrally.client INFO SSL certificate verification: on
2021-08-01 18:53:35,767 ActorAddr-(T|:37860)/PID:31 esrally.client INFO SSL client authentication: off
2021-08-01 18:53:35,767 ActorAddr-(T|:37860)/PID:31 esrally.client INFO HTTP basic authentication: off
2021-08-01 18:53:35,767 ActorAddr-(T|:37860)/PID:31 esrally.client INFO HTTP compression: off
2021-08-01 18:53:35,771 ActorAddr-(T|:37860)/PID:31 esrally.driver.driver INFO Task assertions enabled: False
2021-08-01 18:53:35,771 ActorAddr-(T|:37860)/PID:31 esrally.driver.driver INFO Choosing [unthrottled] for [delete-esrally-2-documents].
2021-08-01 18:53:35,772 ActorAddr-(T|:37860)/PID:31 esrally.driver.driver INFO Creating iteration-count based schedule with [None] distribution for [delete-esrally-2-documents] with [0] warmup iterations and [1] iterations.
2021-08-01 18:53:35,772 ActorAddr-(T|:37860)/PID:31 esrally.driver.driver INFO iteration-count-based schedule will determine when the schedule for [delete-esrally-2-documents] terminates.
2021-08-01 18:53:35,772 ActorAddr-(T|:37860)/PID:31 esrally.driver.driver DEBUG Initializing schedule for client id [0].
2021-08-01 18:53:35,772 ActorAddr-(T|:37860)/PID:31 esrally.driver.driver DEBUG Entering main loop for client id [0].
2021-08-01 18:53:35,795 -not-actor-/PID:31 elasticsearch INFO GET https://<target-ES-cluster>:443/_cluster/settings?flat_settings=true [status:200 request:0.021s]
2021-08-01 18:53:35,795 -not-actor-/PID:31 elasticsearch INFO GET https://<target-ES-cluster>:443/_cluster/settings?flat_settings=true [status:200 request:0.021s]
2021-08-01 18:53:35,795 -not-actor-/PID:31 elasticsearch DEBUG > None
2021-08-01 18:53:35,795 -not-actor-/PID:31 elasticsearch DEBUG > None
2021-08-01 18:53:35,795 -not-actor-/PID:31 elasticsearch DEBUG < b'{"persistent":{"cluster.routing.allocation.cluster_concurrent_rebalance":"2","cluster.routing.allocation.disk.watermark.flood_stage":"4.9214321136474615gb","cluster.routing.allocation.disk.watermark.high":"9.842864227294923gb","cluster.routing.allocation.disk.watermark.low":"14.764296340942382gb","cluster.routing.allocation.node_concurrent_recoveries":"2","cluster.routing.allocation.node_initial_primaries_recoveries":"4","indices.recovery.max_bytes_per_sec":"60mb","opendistro.index_state_management.metadata_migration.status":"1","opendistro.index_state_management.template_migration.control":"-1"},"transient":{"cluster.routing.allocation.cluster_concurrent_rebalance":"2","cluster.routing.allocation.disk.watermark.flood_stage":"4.9214321136474615gb","cluster.routing.allocation.disk.watermark.high":"9.842864227294923gb","cluster.routing.allocation.disk.watermark.low":"14.764296340942382gb","cluster.routing.allocation.exclude.di_number":"","cluster.routing.allocation.node_concurrent_recoveries":"2","cluster.routing.allocation.node_initial_primaries_recoveries":"4","indices.recovery.max_bytes_per_sec":"60mb"}}'
2021-08-01 18:53:35,795 -not-actor-/PID:31 elasticsearch DEBUG < b'{"persistent":{"cluster.routing.allocation.cluster_concurrent_rebalance":"2","cluster.routing.allocation.disk.watermark.flood_stage":"4.9214321136474615gb","cluster.routing.allocation.disk.watermark.high":"9.842864227294923gb","cluster.routing.allocation.disk.watermark.low":"14.764296340942382gb","cluster.routing.allocation.node_concurrent_recoveries":"2","cluster.routing.allocation.node_initial_primaries_recoveries":"4","indices.recovery.max_bytes_per_sec":"60mb","opendistro.index_state_management.metadata_migration.status":"1","opendistro.index_state_management.template_migration.control":"-1"},"transient":{"cluster.routing.allocation.cluster_concurrent_rebalance":"2","cluster.routing.allocation.disk.watermark.flood_stage":"4.9214321136474615gb","cluster.routing.allocation.disk.watermark.high":"9.842864227294923gb","cluster.routing.allocation.disk.watermark.low":"14.764296340942382gb","cluster.routing.allocation.exclude.di_number":"","cluster.routing.allocation.node_concurrent_recoveries":"2","cluster.routing.allocation.node_initial_primaries_recoveries":"4","indices.recovery.max_bytes_per_sec":"60mb"}}'
2021-08-01 18:53:35,798 -not-actor-/PID:31 elasticsearch WARNING PUT https://<target-ES-cluster>:443/_cluster/settings [status:401 request:0.002s]
2021-08-01 18:53:35,798 -not-actor-/PID:31 elasticsearch WARNING PUT https://<target-ES-cluster>:443/_cluster/settings [status:401 request:0.002s]
2021-08-01 18:53:35,798 -not-actor-/PID:31 elasticsearch DEBUG > {"transient":{"action.destructive_requires_name":false}}
2021-08-01 18:53:35,798 -not-actor-/PID:31 elasticsearch DEBUG > {"transient":{"action.destructive_requires_name":false}}
2021-08-01 18:53:35,798 -not-actor-/PID:31 elasticsearch DEBUG < b'{"Message":"Your request: \'/_cluster/settings\' payload is not allowed."}'
2021-08-01 18:53:35,798 -not-actor-/PID:31 elasticsearch DEBUG < b'{"Message":"Your request: \'/_cluster/settings\' payload is not allowed."}'
2021-08-01 18:53:35,799 ActorAddr-(T|:37860)/PID:31 esrally.driver.driver ERROR Could not execute schedule
Traceback (most recent call last):

  File "/usr/local/lib/python3.8/site-packages/esrally/driver/driver.py", line 1567, in __call__
    total_ops, total_ops_unit, request_meta_data = await execute_single(runner, self.es, params, self.on_error)

  File "/usr/local/lib/python3.8/site-packages/esrally/driver/driver.py", line 1687, in execute_single
    raise exceptions.RallyAssertionError(msg)

esrally.exceptions.RallyAssertionError: Request returned an error. Error type: transport, Description: b'{"Message":"Your request: \'/_cluster/settings\' payload is not allowed."}' ({'Message': "Your request: '/_cluster/settings' payload is not allowed."})

2021-08-01 18:53:35,800 ActorAddr-(T|:39145)/PID:24 esrally.driver.driver DEBUG Resetting relative time of request metrics store.
2021-08-01 18:53:35,800 ActorAddr-(T|:37860)/PID:31 esrally.driver.driver INFO Total run duration: 0.027655 seconds.
2021-08-01 18:53:35,801 ActorAddr-(T|:37860)/PID:31 esrally.driver.driver INFO Total time to shutdown asyncgens: 0.000726 seconds.
2021-08-01 18:53:35,802 ActorAddr-(T|:37860)/PID:31 esrally.driver.driver INFO Total time to close transports: -0.001563 seconds.
2021-08-01 18:53:40,761 ActorAddr-(T|:37860)/PID:31 esrally.actor ERROR Worker[0] has detected a benchmark failure. Notifying master...
Traceback (most recent call last):

So far I think it has to do with some security setting on the cluster but I am certain I have given all the required access to the client.

Any feedback would be appreciated.

2

Hi,

actually, only the delete-index task should fail; create-index should work fine. I think the reason why the call is failing is that the AWS Elasticsearch service prohibits calling the _cluster/settings API. See Ensure destructive actions work regardless of wildcard input by DJRickyB · Pull Request #1243 · elastic/rally · GitHub for the reason why Rally is calling that API at all when deleting indices.

A pragmatic workaround in your case (you only have one index), is to use Rally's raw-request. If you replace:

{
      "operation" : {
        "name": "delete-esrally-2-documents",
        "operation-type": "delete-index",
        "index": "esrally-2-documents"
      }
}

with:

{
  "operation" : {
    "name": "delete-esrally-2-documents",
    "operation-type": "raw-request",
    "method": "DELETE",
    "path": "/esrally-2-documents"
  }
}

I did not test this locally but after this change the index should be deleted as expected.

Hope that helps.

Daniel

2 Likes
3

This works as intended ! Thanks a lot !

4

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