[CI] testRelocationWithConcurrentIndexing fails

[dnhatn]

This test is failing on the master branch.

Error: no data nodes with criteria [dBUFa2wKQMiz0s9AKZXg8g]

   > Throwable #1: org.elasticsearch.client.ResponseException: method [GET], host [http://[::1]:42932], URI [relocation_with_concurrent_indexing/_count?preference=_only_nodes%3AdBUFa2wKQMiz0s9AKZXg8g], status line [HTTP/1.1 400 Bad Request]
   > {"error":{"root_cause":[{"type":"illegal_argument_exception","reason":"no data nodes with criteria [dBUFa2wKQMiz0s9AKZXg8g] found for shard: [relocation_with_concurrent_indexing][0]"}],"type":"illegal_argument_exception","reason":"no data nodes with criteria [dBUFa2wKQMiz0s9AKZXg8g] found for shard: [relocation_with_concurrent_indexing][0]"},"status":400}

./gradlew :qa:rolling-upgrade:v6.6.0-SNAPSHOT#oneThirdUpgradedTestRunner \
  -Dtests.seed=21AA246620D7D177 \
  -Dtests.class=org.elasticsearch.upgrades.RecoveryIT \
  -Dtests.method="testRelocationWithConcurrentIndexing" \
  -Dtests.security.manager=true \
  -Dtests.locale=es-PE \
  -Dtests.timezone=Asia/Atyrau \
  -Dcompiler.java=11 \
  -Druntime.java=8

CI instances:

• https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+periodic/73/console
• https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+release-tests/36/console

[elasticmachine]

Pinging @elastic/es-distributed

[DaveCTurner]

Investigating this. I will try and obtain the logs from the nodes in question.

[DaveCTurner]

I suspect #34950 has surfaced this issue. Before #34950 we had minimum_master_nodes set to 3 in the rolling-upgrade cluster which meant that there was no master while each node went away for an upgrade. Since #34950 we have minimum_master_nodes set to 2 so the master survives and possibly does things while the cluster is incomplete. The master node logs:

[2018-10-28T22:39:16,154][INFO ][o.e.c.s.MasterService    ] [node-2] zen-disco-node-failed({node-0}{dBUFa2wKQMiz0s9AKZXg8g}{u5OgRWsKQauhUhBP6S0bNA}{127.0.0.1}{127.0.0.1:46796}{testattr=test}), reason(transport disconnected)[{node-0}{dBUFa2wKQMiz0s9AKZXg8g}{u5OgRWsKQauhUhBP6S0bNA}{127.0.0.1}{127.0.0.1:46796}{testattr=test} transport disconnected], reason: removed {{node-0}{dBUFa2wKQMiz0s9AKZXg8g}{u5OgRWsKQauhUhBP6S0bNA}{127.0.0.1}{127.0.0.1:46796}{testattr=test},}
[2018-10-28T22:39:16,273][INFO ][o.e.c.s.ClusterApplierService] [node-2] removed {{node-0}{dBUFa2wKQMiz0s9AKZXg8g}{u5OgRWsKQauhUhBP6S0bNA}{127.0.0.1}{127.0.0.1:46796}{testattr=test},}, reason: apply cluster state (from master [master {node-2}{-QA0MXO6RyW8LhiIJvxBcA}{I7ULDGeeTsujKeMZ9Fqkyg}{127.0.0.1}{127.0.0.1:46066}{testattr=test} committed version [71] source [zen-disco-node-failed({node-0}{dBUFa2wKQMiz0s9AKZXg8g}{u5OgRWsKQauhUhBP6S0bNA}{127.0.0.1}{127.0.0.1:46796}{testattr=test}), reason(transport disconnected)[{node-0}{dBUFa2wKQMiz0s9AKZXg8g}{u5OgRWsKQauhUhBP6S0bNA}{127.0.0.1}{127.0.0.1:46796}{testattr=test} transport disconnected]]])
[2018-10-28T22:39:16,298][INFO ][o.e.i.s.IndexShard       ] [node-2] [reindexed_index_copy][3] primary-replica resync completed with 0 operations
[2018-10-28T22:39:16,300][INFO ][o.e.i.s.IndexShard       ] [node-2] [test_search_template][3] primary-replica resync completed with 0 operations
[2018-10-28T22:39:16,304][INFO ][o.e.i.s.IndexShard       ] [node-2] [queries][1] primary-replica resync completed with 0 operations
[2018-10-28T22:39:16,308][INFO ][o.e.i.s.IndexShard       ] [node-2] [index_with_replicas][1] primary-replica resync completed with 0 operations
[2018-10-28T22:39:16,314][INFO ][o.e.i.s.IndexShard       ] [node-2] [index_with_replicas][4] primary-replica resync completed with 0 operations
[2018-10-28T22:39:16,318][INFO ][o.e.i.s.IndexShard       ] [node-2] [recover_synced_flush_index][0] primary-replica resync completed with 0 operations
[2018-10-28T22:39:16,342][INFO ][o.e.c.r.DelayedAllocationService] [node-2] scheduling reroute for delayed shards in [0s] (23 delayed shards)
[2018-10-28T22:39:16,399][INFO ][o.e.c.r.DelayedAllocationService] [node-2] scheduling reroute for delayed shards in [59.7s] (14 delayed shards)
[2018-10-28T22:39:25,949][INFO ][o.e.c.s.MasterService    ] [node-2] zen-disco-node-join[{upgraded-node-0}{dBUFa2wKQMiz0s9AKZXg8g}{BkwfVWIZSMyNNZX28gROWA}{127.0.0.1}{127.0.0.1:33036}{testattr=test}], reason: added {{upgraded-node-0}{dBUFa2wKQMiz0s9AKZXg8g}{BkwfVWIZSMyNNZX28gROWA}{127.0.0.1}{127.0.0.1:33036}{testattr=test},}
[2018-10-28T22:39:26,167][INFO ][o.e.c.s.ClusterApplierService] [node-2] added {{upgraded-node-0}{dBUFa2wKQMiz0s9AKZXg8g}{BkwfVWIZSMyNNZX28gROWA}{127.0.0.1}{127.0.0.1:33036}{testattr=test},}, reason: apply cluster state (from master [master {node-2}{-QA0MXO6RyW8LhiIJvxBcA}{I7ULDGeeTsujKeMZ9Fqkyg}{127.0.0.1}{127.0.0.1:46066}{testattr=test} committed version [80] source [zen-disco-node-join[{upgraded-node-0}{dBUFa2wKQMiz0s9AKZXg8g}{BkwfVWIZSMyNNZX28gROWA}{127.0.0.1}{127.0.0.1:33036}{testattr=test}]]])
[2018-10-28T22:39:26,587][INFO ][o.e.c.r.a.AllocationService] [node-2] Cluster health status changed from [RED] to [YELLOW] (reason: [shards started [[reindexed_index][2], [test_index][1]] ...]).
[2018-10-28T22:39:30,015][WARN ][o.e.c.r.a.AllocationService] [node-2] [recovery_with_concurrent_indexing][0] marking unavailable shards as stale: [W45oWiTESx6kGVZT4J2XNQ]
[2018-10-28T22:39:30,989][INFO ][o.e.c.m.MetaDataUpdateSettingsService] [node-2] updating number_of_replicas to [0] for indices [relocation_with_concurrent_indexing]
[2018-10-28T22:39:31,122][WARN ][o.e.c.r.a.AllocationService] [node-2] [relocation_with_concurrent_indexing][0] marking unavailable shards as stale: [ujllO1ZiTFmw_KwpOQv1uQ, _5ZSl3E5QrKhuXJO_v3Lkw]

However I can't reproduce this because I can't even run the rolling upgrade tests locally at the moment, so I'm going to have to shave that yak first.

[DaveCTurner]

This test looks unsuitable for today's rolling-upgrade test environment in a couple of ways:

elasticsearch/qa/rolling-upgrade/src/test/java/org/elasticsearch/upgrades/RecoveryIT.java

Lines 202 to 203 in 19d6cf1

	// make sure that no shards are allocated, so we can make sure the primary stays on the old node (when one
	// node stops, we lose the master too, so a replica will not be promoted)

Since #34950 this is no longer true.

elasticsearch/qa/rolling-upgrade/src/test/java/org/elasticsearch/upgrades/RecoveryIT.java

Lines 207 to 208 in 19d6cf1

	final String newNode = getNodeId(v -> v.equals(Version.CURRENT));
	final String oldNode = getNodeId(v -> v.before(Version.CURRENT));

Since #30728 there are either two old nodes or two new nodes, so these are no longer as uniquely defined as they were.

I also wonder about its usage of asyncIndexDocs().get() and whether this could just be indexDocs().

I suspect some combination of these things is resulting in this failure. However I have run many hundreds of iterations of this test overnight and none of them failed, which I find surprising given how often it was failing in CI. Also I can't quite construct a sequence of events that explain this failure: we set index.routing.allocation.include._id: dBUFa2wKQMiz0s9AKZXg8g, wait for the index to be green, and yet GET /relocation_with_concurrent_indexing/_count?preference=_only_nodes:dBUFa2wKQMiz0s9AKZXg8g says there's no shard on that node. @dnhatn do you have any insight?