Unexpected error with composite operation

Hello,

I’m trying to run a composite operation in esrally for async search, as the docs mention that async operations need to run inside a composite. However, I’m stumbling on an error and can’t figure out what is wrong, the definition looks fine to me and according to the docs. Running latest version 2.10.0.

The error:

Running query-search-4-composite                                               [  0% done]
[ERROR] Cannot race. Error in load generator [0]
       Cannot run task [query-search-4-composite]: unsupported operand type(s) for -: 'NoneType' and 'NoneType'

From the log file this looks interesting:

  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/driver/runner.py", line 2895, in __call__
    "service_time": end - start,

TypeError: unsupported operand type(s) for -: 'NoneType' and 'NoneType'

The composite operation:

    {
      "operation": {
        "name": "query-search-4-composite",
        "operation-type": "composite",
        "requests": [
          {
            "stream": [
              {
                "name": "query-search-4-submit",
                "operation-type": "submit-async-search",
                "body": {
                  "query": {
                    "bool": {
                      "must": [
                        {
                          "query_string": {
                            "query": "*whatever*"
                          }
                        },
                        {
                          "range": {
                            "@timestamp": {
                              "gte": "now-14d/d",
                              "lt": "now-5d/d"
                            }
                          }
                        }
                      ]
                    }
                  }
                }
              }
            ]
          },
          {
            "name": "query-search-4-get",
            "operation-type": "get-async-search",
            "retrieve-results-for": [
              "query-search-4-submit"
            ]
          },
          {
            "name": "query-search-4-delete",
            "operation-type": "delete-async-search",
            "delete-results-for": [
              "query-search-4-submit"
            ]
          }
        ]
      },
      "clients": 1,
      "warmup-iterations": 1,
      "iterations": 1
    },

The complete error log:

2024-03-11 02:33:28,826 ActorAddr-(T|:42619)/PID:4006 esrally.driver.driver INFO Worker[0] executing tasks: ['query-search-4-composite']
2024-03-11 02:33:29,657 ActorAddr-(T|:42619)/PID:4006 esrally.driver.driver ERROR Could not execute schedule
Traceback (most recent call last):

  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/driver/driver.py", line 1920, in __call__
    total_ops, total_ops_unit, request_meta_data = await execute_single(runner, self.es, params, self.on_error)

  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/driver/driver.py", line 2014, in execute_single
    return_value = await runner(es, params)

  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/driver/runner.py", line 297, in __call__
    return await self.delegate(*args)

  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/driver/runner.py", line 412, in __call__
    return_value = await self.delegate(*args)

  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/driver/runner.py", line 345, in __call__
    return await self.delegate(self.client_extractor(args[0]), *args[1:])

  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/driver/runner.py", line 2665, in __call__
    response = await self.run_stream(es, requests, asyncio.BoundedSemaphore(max_connections))

  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/driver/runner.py", line 2633, in run_stream
    response = await runner({"default": es}, item)

  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/driver/runner.py", line 2895, in __call__
    "service_time": end - start,

TypeError: unsupported operand type(s) for -: 'NoneType' and 'NoneType'

2024-03-11 02:33:29,658 ActorAddr-(T|:42619)/PID:4006 esrally.driver.driver INFO Worker[0] finished executing tasks ['query-search-4-composite'] in 0.832510 seconds
2024-03-11 02:33:33,820 ActorAddr-(T|:42619)/PID:4006 esrally.actor ERROR Worker[0] has detected a benchmark failure. Notifying master...
Traceback (most recent call last):

  File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)

  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/driver/driver.py", line 1765, in __call__
    loop.run_until_complete(self.run())

  File "/usr/local/lib/python3.9/asyncio/base_events.py", line 647, in run_until_complete
    return future.result()

  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/driver/driver.py", line 1817, in run
    _ = await asyncio.gather(*awaitables)

  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/driver/driver.py", line 1982, in __call__
    raise exceptions.RallyError(f"Cannot run task [{self.task}]: {e}") from None

esrally.exceptions.RallyError: Cannot run task [query-search-4-composite]: unsupported operand type(s) for -: 'NoneType' and 'NoneType'

2024-03-11 02:33:33,821 ActorAddr-(T|:45427)/PID:2710 esrally.actor ERROR Main driver received a fatal exception from a load generator. Shutting down.
2024-03-11 02:33:33,821 ActorAddr-(T|:45427)/PID:2710 esrally.metrics INFO Closing metrics store.
2024-03-11 02:33:33,845 ActorAddr-(T|:34027)/PID:2699 esrally.actor INFO Received a benchmark failure from [ActorAddr-(T|:45427)] and will forward it now.
2024-03-11 02:33:33,847 -not-actor-/PID:2687 esrally.racecontrol ERROR A benchmark failure has occurred
2024-03-11 02:33:33,847 -not-actor-/PID:2687 esrally.racecontrol INFO Telling benchmark actor to exit.
2024-03-11 02:33:33,851 ActorAddr-(T|:45427)/PID:2710 esrally.actor INFO Main driver received ActorExitRequest and will terminate all load generators.
2024-03-11 02:33:36,851 -not-actor-/PID:2687 esrally.rally INFO Attempting to shutdown internal actor system.
2024-03-11 02:33:36,854 -not-actor-/PID:2698 root INFO ActorSystem Logging Shutdown
2024-03-11 02:33:36,875 -not-actor-/PID:2697 root INFO ---- Actor System shutdown
2024-03-11 02:33:36,876 -not-actor-/PID:2687 esrally.rally INFO Actor system is still running. Waiting...
2024-03-11 02:33:37,877 -not-actor-/PID:2687 esrally.rally INFO Shutdown completed.
2024-03-11 02:33:37,877 -not-actor-/PID:2687 esrally.rally ERROR Cannot run subcommand [race].
Traceback (most recent call last):
  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/rally.py", line 1183, in dispatch_sub_command
    race(cfg, args.kill_running_processes)
  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/rally.py", line 931, in race
    with_actor_system(racecontrol.run, cfg)
  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/rally.py", line 961, in with_actor_system
    runnable(cfg)
  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/racecontrol.py", line 399, in run
    raise e
  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/racecontrol.py", line 396, in run
    pipeline(cfg)
  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/racecontrol.py", line 72, in __call__
    self.target(cfg)
  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/racecontrol.py", line 335, in benchmark_only
    return race(cfg, external=True)
  File "/home/rpereira/venv-esrally/lib/python3.9/site-packages/esrally/racecontrol.py", line 293, in race
    raise exceptions.RallyError(result.message, result.cause)
esrally.exceptions.RallyError: Error in load generator [0]

elastic / rally

Unexpected error with composite operation #1837