Could not start node in 20.0 seconds. Cannot find any errors though

Alexander_Gray_II · November 4, 2016, 6:19pm

I'm running rally on an AWS m3.medium box with esrally 0.4.3, and I'm running the following command:

esrally --pipeline=from-distribution --distribution-version=5.0.0

It dies after 20 seconds, but I don't see any errors in the logs:

2016-11-04 18:06:55,509 rally.launcher INFO ES launch: ['bin/elasticsearch', '-Enode.name=rally-node0', '-Epath.logs=/home/ec2-user/.rally/benchmarks/races/2016-11-04-18-06-50/local/logs/geonames/append-no-conflicts/server']
2016-11-04 18:07:00,777 rally.launcher INFO rally-node0: [2016-11-04T18:07:00,765][INFO ][o.e.n.Node               ] [rally-node0] initializing ...
2016-11-04 18:07:00,970 rally.launcher INFO rally-node0: [2016-11-04T18:07:00,969][INFO ][o.e.e.NodeEnvironment    ] [rally-node0] using [1] data paths, mounts [[/ (/dev/xvda1)]], net usable_space [10.2gb], net total_space [11.6gb], spins? [no], types [ext4]
2016-11-04 18:07:00,971 rally.launcher INFO rally-node0: [2016-11-04T18:07:00,970][INFO ][o.e.e.NodeEnvironment    ] [rally-node0] heap size [1.9gb], compressed ordinary object pointers [true]
2016-11-04 18:07:00,975 rally.launcher INFO rally-node0: [2016-11-04T18:07:00,975][INFO ][o.e.n.Node               ] [rally-node0] version[5.0.0], pid[2619], build[253032b/2016-10-26T04:37:51.531Z], OS[Linux/4.4.19-29.55.amzn1.x86_64/amd64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/1.8.0_111/25.111-b15]
2016-11-04 18:07:05,295 rally.launcher INFO rally-node0: [2016-11-04T18:07:05,295][INFO ][o.e.p.PluginsService     ] [rally-node0] loaded module [aggs-matrix-stats]
2016-11-04 18:07:05,296 rally.launcher INFO rally-node0: [2016-11-04T18:07:05,295][INFO ][o.e.p.PluginsService     ] [rally-node0] loaded module [ingest-common]
2016-11-04 18:07:05,296 rally.launcher INFO rally-node0: [2016-11-04T18:07:05,296][INFO ][o.e.p.PluginsService     ] [rally-node0] loaded module [lang-expression]
2016-11-04 18:07:05,296 rally.launcher INFO rally-node0: [2016-11-04T18:07:05,296][INFO ][o.e.p.PluginsService     ] [rally-node0] loaded module [lang-groovy]
2016-11-04 18:07:05,296 rally.launcher INFO rally-node0: [2016-11-04T18:07:05,296][INFO ][o.e.p.PluginsService     ] [rally-node0] loaded module [lang-mustache]
2016-11-04 18:07:05,296 rally.launcher INFO rally-node0: [2016-11-04T18:07:05,296][INFO ][o.e.p.PluginsService     ] [rally-node0] loaded module [lang-painless]
2016-11-04 18:07:05,297 rally.launcher INFO rally-node0: [2016-11-04T18:07:05,297][INFO ][o.e.p.PluginsService     ] [rally-node0] loaded module [percolator]
2016-11-04 18:07:05,297 rally.launcher INFO rally-node0: [2016-11-04T18:07:05,297][INFO ][o.e.p.PluginsService     ] [rally-node0] loaded module [reindex]
2016-11-04 18:07:05,298 rally.launcher INFO rally-node0: [2016-11-04T18:07:05,298][INFO ][o.e.p.PluginsService     ] [rally-node0] loaded module [transport-netty3]
2016-11-04 18:07:05,298 rally.launcher INFO rally-node0: [2016-11-04T18:07:05,298][INFO ][o.e.p.PluginsService     ] [rally-node0] loaded module [transport-netty4]
2016-11-04 18:07:05,299 rally.launcher INFO rally-node0: [2016-11-04T18:07:05,299][INFO ][o.e.p.PluginsService     ] [rally-node0] no plugins loaded
2016-11-04 18:07:13,621 rally.launcher INFO rally-node0: [2016-11-04T18:07:13,621][INFO ][o.e.n.Node               ] [rally-node0] initialized
2016-11-04 18:07:13,624 rally.launcher INFO rally-node0: [2016-11-04T18:07:13,624][INFO ][o.e.n.Node               ] [rally-node0] starting ...
2016-11-04 18:07:14,103 rally.launcher INFO rally-node0: [2016-11-04T18:07:14,103][INFO ][o.e.t.TransportService   ] [rally-node0] publish_address {127.0.0.1:39300}, bound_addresses {[::1]:39300}, {127.0.0.1:39300}
2016-11-04 18:07:15,513 rally.launcher ERROR Could not start node 'rally-node0' within timeout period of 20.0 seconds.

My rally.ini is pretty vanilla:

[meta]
config.version = 6

[system]
root.dir = /home/ec2-user/.rally/benchmarks
log.root.dir = logs
env.name = local

[provisioning]
local.install.dir = install

[runtime]
java8.home = /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.111-1.b15.25.amzn1.x86_64

[benchmarks]
local.dataset.cache = ${system:root.dir}/data

[reporting]
datastore.type = in-memory
datastore.host =
datastore.port =
datastore.secure =
datastore.user =
datastore.password =

[tracks]
default.url = https://github.com/elastic/rally-tracks

[defaults]
preserve_benchmark_candidate = False

I'm not sure what the error could be. Is there a way to tweak the 20.0 second timeout value?

Alexander_Gray_II · November 4, 2016, 6:35pm

Note: I manually tweaked the value to 30s, and now the tests start:

github.com

elastic/rally/blob/master/esrally/mechanic/launcher.py#L217


    logger.info("Detected Java major version [%s]." % java_major_version)


    node_count_on_host = len(node_configurations)
    return [self._start_node(node_configuration, node_count_on_host, java_major_version) for node_configuration in node_configurations]


def _start_node(self, node_configuration, node_count_on_host, java_major_version):
    host_name = node_configuration.ip
    node_name = node_configuration.node_name
    car = node_configuration.car
    binary_path = node_configuration.binary_path
    data_paths = node_configuration.data_paths
    node_telemetry_dir = "%s/telemetry" % node_configuration.node_root_path


    logger.info("Starting node [%s] based on car [%s]." % (node_name, car))


    enabled_devices = self.cfg.opts("mechanic", "telemetry.devices")
    node_telemetry = [
        telemetry.FlightRecorder(node_telemetry_dir, java_major_version),
        telemetry.JitCompiler(node_telemetry_dir),
        telemetry.Gc(node_telemetry_dir, java_major_version),
        telemetry.PerfStat(node_telemetry_dir),

I think it was just taking a few seconds longer than 20s to come up.

m3.medium is pretty small:
3.75 GB Memory, 3 ECU units, 1 vCPUs 4.0 GB SSD

Basically, I'm trying to find the cheapest instance to run rally on (just to work out all the kinks) before increasing the size.

danielmitterdorfer · November 4, 2016, 6:39pm

Hi @Alexander_Gray_II,

20 seconds was a good default on all platforms we've tested on. Thanks for spotting it. I can increase the timeout for Rally 0.4.4.

Daniel