Error when running race

Hank.S · July 8, 2024, 8:17am

I'm new to rally and want to test my elastic cluster's performance.
I have a 3-node elastic cluster set in docker.
I'm in China mainland, so it could be a network issue.

I installed esrally in a virtual venv of python3.8.

esrally race --track geonames --target-hosts 127.0.0.1:9200 --pipeline=benchmark-only is working great.
esrally race --track elastic/logs --target-hosts 127.0.0.1:9200 --pipeline=benchmark-only exited with error

(venv) [sxing@archlinux ~]$ esrally race --track elastic/logs --target-hosts 127.0.0.1:9200 --pipeline=benchmark-only

    ____        ____
   / __ \____ _/ / /_  __
  / /_/ / __ `/ / / / / /
 / _, _/ /_/ / / / /_/ /
/_/ |_|\__,_/_/_/\__, /
                /____/

[INFO] Race id is [5aa90fff-d6ba-486e-9ae2-b71afee6c8de]

[ERROR] Cannot race. Traceback (most recent call last):
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 712, in load_template_from_file
    base_track = loader.get_source(jinja2.Environment(), self.template_file_name)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/jinja2/loaders.py", line 207, in get_source
    raise TemplateNotFound(template)
jinja2.exceptions.TemplateNotFound: track.json

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 1109, in read
    rendered = render_template_from_file(
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 832, in render_template_from_file
    template_source.load_template_from_file()
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 715, in load_template_from_file
    raise TrackSyntaxError(f"Could not load track from '{self.template_file_name}'")
esrally.track.loader.TrackSyntaxError: Could not load track from 'track.json'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/actor.py", line 92, in guard
    return f(self, msg, sender)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/racecontrol.py", line 114, in receiveMsg_Setup
    self.coordinator.setup(sources=msg.sources)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/racecontrol.py", line 228, in setup
    self.current_track = track.load_track(self.cfg, install_dependencies=True)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 215, in load_track
    return _load_single_track(cfg, repo, repo.track_name, install_dependencies)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 237, in _load_single_track
    current_track = reader.read(track_name, track_repository.track_file(track_name), track_dir)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 1140, in read
    raise TrackSyntaxError(msg, e)
esrally.track.loader.TrackSyntaxError: Could not load '/home/sxing/.rally/benchmarks/tracks/default/elastic/logs/track.json'. The complete track has been written to '/tmp/tmpmm11vhqj.json' for diagnosis.


Getting further help:
*********************
* Check the log files in /home/sxing/.rally/logs for errors.
* Read the documentation at https://esrally.readthedocs.io/en/2.11.0/.
* Ask a question on the forum at https://discuss.elastic.co/tags/c/elastic-stack/elasticsearch/rally.
* Raise an issue at https://github.com/elastic/rally/issues and include the log files in /home/sxing/.rally/logs.

-------------------------------
[INFO] FAILURE (took 4 seconds)
-------------------------------

full log:

2024-07-08 08:11:46,411 -not-actor-/PID:93644 esrally.rally INFO OS [uname_result(system='Linux', node='archlinux', release='6.9.7-zen1-1-zen', version='#1 ZEN SMP PREEMPT_DYNAMIC Fri, 28 Jun 2024 04:32:27 +0000', machine='x86_64', processor='')]
2024-07-08 08:11:46,411 -not-actor-/PID:93644 esrally.rally INFO Python [namespace(_multiarch='x86_64-linux-gnu', cache_tag='cpython-38', hexversion=50861040, name='cpython', version=sys.version_info(major=3, minor=8, micro=19, releaselevel='final', serial=0))]
2024-07-08 08:11:46,411 -not-actor-/PID:93644 esrally.rally INFO Rally version [2.11.0]
2024-07-08 08:11:46,411 -not-actor-/PID:93644 esrally.utils.net INFO Connecting via proxy URL [http://sxing:4568@172.20.176.1:23333] to the Internet (picked up from the environment variable [http_proxy]).
2024-07-08 08:11:46,411 -not-actor-/PID:93644 esrally.utils.net INFO Connecting via proxy URL [http://sxing:4568@172.20.176.1:23333] to the Internet (picked up from the environment variable [https_proxy]).
2024-07-08 08:11:46,411 -not-actor-/PID:93644 esrally.rally INFO Cleaning track dependency directory [/home/sxing/.rally/libs]...
2024-07-08 08:11:46,425 -not-actor-/PID:93644 esrally.rally INFO Actor system already running locally? [False]
2024-07-08 08:11:46,425 -not-actor-/PID:93644 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'}].
2024-07-08 08:11:46,432 -not-actor-/PID:93653 root INFO ++++ Actor System gen (3, 10) started, admin @ ActorAddr-(T|:1900)
2024-07-08 08:11:46,437 -not-actor-/PID:93644 esrally.racecontrol INFO Race id is [5aa90fff-d6ba-486e-9ae2-b71afee6c8de]
2024-07-08 08:11:46,437 -not-actor-/PID:93644 esrally.racecontrol INFO User specified pipeline [benchmark-only].
2024-07-08 08:11:46,437 -not-actor-/PID:93644 esrally.racecontrol INFO Using configured hosts [{'host': '127.0.0.1', 'port': 9200}]
2024-07-08 08:11:46,438 ActorAddr-(T|:1900)/PID:93653 esrally.actor DEBUG 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, 19, 'final', 0), 'Thespian Generation': (3, 10), 'Thespian Version': '1720426306429'}] match requirements [{'coordinator': True}].
2024-07-08 08:11:47,322 -not-actor-/PID:93644 esrally.racecontrol ERROR A benchmark failure has occurred
2024-07-08 08:11:47,322 -not-actor-/PID:93644 esrally.racecontrol INFO Telling benchmark actor to exit.
2024-07-08 08:11:46,442 ActorAddr-(T|:38205)/PID:93655 esrally.client.factory INFO Creating ES client connected to [{'host': '127.0.0.1', 'port': 9200}] with options [{'timeout': 60}]
2024-07-08 08:11:46,475 ActorAddr-(T|:38205)/PID:93655 esrally.racecontrol INFO Automatically derived distribution flavor [default], version [7.10.1], and build hash [1c34507e66d7db1211f66f3513706fdf548736aa]
2024-07-08 08:11:47,304 ActorAddr-(T|:38205)/PID:93655 esrally.utils.repo INFO Checking out [7.2] in [/home/sxing/.rally/benchmarks/tracks/default] for distribution version [7.10.1].
2024-07-08 08:11:47,308 ActorAddr-(T|:38205)/PID:93655 esrally.utils.process INFO Already on '7.2'
Your branch is up to date with 'origin/7.2'.

2024-07-08 08:11:47,308 ActorAddr-(T|:38205)/PID:93655 esrally.utils.repo INFO Rebasing on [7.2] in [/home/sxing/.rally/benchmarks/tracks/default] for distribution version [7.10.1].
2024-07-08 08:11:47,314 ActorAddr-(T|:38205)/PID:93655 esrally.utils.process INFO Already on '7.2'
Your branch is up to date with 'origin/7.2'.

2024-07-08 08:11:47,316 ActorAddr-(T|:38205)/PID:93655 esrally.utils.process INFO Current branch 7.2 is up to date.

2024-07-08 08:11:47,320 ActorAddr-(T|:38205)/PID:93655 esrally.track.loader INFO Reading track specification file [/home/sxing/.rally/benchmarks/tracks/default/elastic/logs/track.json].
2024-07-08 08:11:47,320 ActorAddr-(T|:38205)/PID:93655 esrally.track.loader ERROR Could not load track from [track.json].
Traceback (most recent call last):

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 712, in load_template_from_file
    base_track = loader.get_source(jinja2.Environment(), self.template_file_name)

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/jinja2/loaders.py", line 207, in get_source
    raise TemplateNotFound(template)

jinja2.exceptions.TemplateNotFound: track.json

2024-07-08 08:11:47,321 ActorAddr-(T|:38205)/PID:93655 esrally.track.loader ERROR Could not load [/home/sxing/.rally/benchmarks/tracks/default/elastic/logs/track.json].
Traceback (most recent call last):

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 712, in load_template_from_file
    base_track = loader.get_source(jinja2.Environment(), self.template_file_name)

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/jinja2/loaders.py", line 207, in get_source
    raise TemplateNotFound(template)

jinja2.exceptions.TemplateNotFound: track.json


During handling of the above exception, another exception occurred:


Traceback (most recent call last):

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 1109, in read
    rendered = render_template_from_file(

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 832, in render_template_from_file
    template_source.load_template_from_file()

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 715, in load_template_from_file
    raise TrackSyntaxError(f"Could not load track from '{self.template_file_name}'")

esrally.track.loader.TrackSyntaxError: Could not load track from 'track.json'

2024-07-08 08:11:47,321 ActorAddr-(T|:38205)/PID:93655 esrally.track.loader ERROR Cannot load track [elastic/logs]
Traceback (most recent call last):

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 712, in load_template_from_file
    base_track = loader.get_source(jinja2.Environment(), self.template_file_name)

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/jinja2/loaders.py", line 207, in get_source
    raise TemplateNotFound(template)

jinja2.exceptions.TemplateNotFound: track.json


During handling of the above exception, another exception occurred:


Traceback (most recent call last):

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 1109, in read
    rendered = render_template_from_file(

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 832, in render_template_from_file
    template_source.load_template_from_file()

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 715, in load_template_from_file
    raise TrackSyntaxError(f"Could not load track from '{self.template_file_name}'")

esrally.track.loader.TrackSyntaxError: Could not load track from 'track.json'


During handling of the above exception, another exception occurred:


Traceback (most recent call last):

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 237, in _load_single_track
    current_track = reader.read(track_name, track_repository.track_file(track_name), track_dir)

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 1140, in read
    raise TrackSyntaxError(msg, e)

esrally.track.loader.TrackSyntaxError: Could not load '/home/sxing/.rally/benchmarks/tracks/default/elastic/logs/track.json'. The complete track has been written to '/tmp/tmpmm11vhqj.json' for diagnosis.

2024-07-08 08:11:47,321 ActorAddr-(T|:38205)/PID:93655 esrally.actor ERROR Error in race control
Traceback (most recent call last):

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 712, in load_template_from_file
    base_track = loader.get_source(jinja2.Environment(), self.template_file_name)

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/jinja2/loaders.py", line 207, in get_source
    raise TemplateNotFound(template)

jinja2.exceptions.TemplateNotFound: track.json


During handling of the above exception, another exception occurred:


Traceback (most recent call last):

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 1109, in read
    rendered = render_template_from_file(

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 832, in render_template_from_file
    template_source.load_template_from_file()

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 715, in load_template_from_file
    raise TrackSyntaxError(f"Could not load track from '{self.template_file_name}'")

esrally.track.loader.TrackSyntaxError: Could not load track from 'track.json'


During handling of the above exception, another exception occurred:


Traceback (most recent call last):

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/actor.py", line 92, in guard
    return f(self, msg, sender)

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/racecontrol.py", line 114, in receiveMsg_Setup
    self.coordinator.setup(sources=msg.sources)

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/racecontrol.py", line 228, in setup
    self.current_track = track.load_track(self.cfg, install_dependencies=True)

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 215, in load_track
    return _load_single_track(cfg, repo, repo.track_name, install_dependencies)

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 237, in _load_single_track
    current_track = reader.read(track_name, track_repository.track_file(track_name), track_dir)

  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 1140, in read
    raise TrackSyntaxError(msg, e)

esrally.track.loader.TrackSyntaxError: Could not load '/home/sxing/.rally/benchmarks/tracks/default/elastic/logs/track.json'. The complete track has been written to '/tmp/tmpmm11vhqj.json' for diagnosis.

2024-07-08 08:11:50,326 -not-actor-/PID:93644 esrally.rally INFO Attempting to shutdown internal actor system.
2024-07-08 08:11:50,327 -not-actor-/PID:93654 root INFO ActorSystem Logging Shutdown
2024-07-08 08:11:50,347 -not-actor-/PID:93653 root INFO ---- Actor System shutdown
2024-07-08 08:11:50,347 -not-actor-/PID:93644 esrally.rally INFO Actor system is still running. Waiting...
2024-07-08 08:11:51,348 -not-actor-/PID:93644 esrally.rally INFO Shutdown completed.
2024-07-08 08:11:51,348 -not-actor-/PID:93644 esrally.rally ERROR Cannot run subcommand [race].
Traceback (most recent call last):
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/rally.py", line 1189, in dispatch_sub_command
    race(cfg, args.kill_running_processes)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/rally.py", line 937, in race
    with_actor_system(racecontrol.run, cfg)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/rally.py", line 967, in with_actor_system
    runnable(cfg)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/racecontrol.py", line 408, in run
    raise e
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/racecontrol.py", line 405, in run
    pipeline(cfg)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/racecontrol.py", line 74, in __call__
    self.target(cfg)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/racecontrol.py", line 344, in benchmark_only
    return race(cfg, external=True)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/racecontrol.py", line 302, in race
    raise exceptions.RallyError(result.message, result.cause)
esrally.exceptions.RallyError: Traceback (most recent call last):
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 712, in load_template_from_file
    base_track = loader.get_source(jinja2.Environment(), self.template_file_name)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/jinja2/loaders.py", line 207, in get_source
    raise TemplateNotFound(template)
jinja2.exceptions.TemplateNotFound: track.json

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 1109, in read
    rendered = render_template_from_file(
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 832, in render_template_from_file
    template_source.load_template_from_file()
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 715, in load_template_from_file
    raise TrackSyntaxError(f"Could not load track from '{self.template_file_name}'")
esrally.track.loader.TrackSyntaxError: Could not load track from 'track.json'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/actor.py", line 92, in guard
    return f(self, msg, sender)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/racecontrol.py", line 114, in receiveMsg_Setup
    self.coordinator.setup(sources=msg.sources)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/racecontrol.py", line 228, in setup
    self.current_track = track.load_track(self.cfg, install_dependencies=True)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 215, in load_track
    return _load_single_track(cfg, repo, repo.track_name, install_dependencies)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 237, in _load_single_track
    current_track = reader.read(track_name, track_repository.track_file(track_name), track_dir)
  File "/home/sxing/esrally/venv/lib/python3.8/site-packages/esrally/track/loader.py", line 1140, in read
    raise TrackSyntaxError(msg, e)
esrally.track.loader.TrackSyntaxError: Could not load '/home/sxing/.rally/benchmarks/tracks/default/elastic/logs/track.json'. The complete track has been written to '/tmp/tmpmm11vhqj.json' for diagnosis.

gareth-ellis · July 8, 2024, 8:59am

Hello!

Rally uses various branches of repos such as rally-tracks for ensuring that the tracks are compatible with the version of Elasticsearch that is being tested.

You seem to be running a version of elasticsearch around 7.2, so rally is trying to use the 7.2 branch of rally-tracks. Elastic/logs doesn't exist in the 7.2 branch.

We can see this from

2024-07-08 08:11:47,314 ActorAddr-(T|:38205)/PID:93655 esrally.utils.process INFO Already on '7.2'
Your branch is up to date with 'origin/7.2'.

If you were actually wanting to be running a much later version of Elasticsearch, then take a look at the configuration of your docker environment to find why an older image is being used

If however you want to be running against a v7.2 (or there abouts) version of Elasticsearch, then you could try checking out master (ie go into /home/sxing/.rally/benchmarks/tracks/default and do git checkout master and doing something like --track-path /home/sxing/.rally/benchmarks/tracks/default/elastic/logs . Note though some features of the track may be incompatible with Elasticsearch 7.2

Hank.S · July 9, 2024, 2:32am

Thanks! That solves my error