search

elastic / elasticsearch

Free and Open Source, Distributed, RESTful Search Engine
https://www.elastic.co/products/elasticsearch
Other
69.95k stars 24.74k forks source link

ZenDiscoveryIT#testDiscoveryStats fails on unexpected processed item #24388

Closed nik9000 closed 7 years ago

nik9000 commented 7 years ago

ZenDiscoveryIT#testDiscoveryStats fails because it sees an unexpected cluster state update during the test. I'm not sure why and don't have time to figure it out right now. Here is the failure link: https://elasticsearch-ci.elastic.co/job/elastic+elasticsearch+master+multijob-unix-compatibility/os=fedora/900/consoleFull

The reproduction line from Jenkins (doesn't reproduce for me though) is:

  2> REPRODUCE WITH: gradle :core:integTest -Dtests.seed=2A1090722DFCC931 -Dtests.class=org.elasticsearch.discovery.zen.ZenDiscoveryIT -Dtests.method="testDiscoveryStats" -Dtests.security.manager=true -Dtests.locale=es-PY -Dtests.timezone=VST
  2> NOTE: leaving temporary files on disk at: /var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora/core/build/testrun/integTest/J1/temp/org.elasticsearch.discovery.zen.ZenDiscoveryIT_2A1090722DFCC931-001
  2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1335, maxMBSortInHeap=7.761239469963075, sim=RandomSimilarity(queryNorm=false): {}, locale=es-PY, timezone=VST
  2> NOTE: Linux 4.8.6-300.fc25.x86_64 amd64/Oracle Corporation 1.8.0_131 (64-bit)/cpus=4,threads=1,free=392213608,total=521142272
  2> NOTE: All tests run in this JVM: [AliasRoutingIT, UpdateIT, MissingValueIT, ShardInfoIT, MinDocCountIT, MultiTermVectorsIT, UpdateNumberOfReplicasIT, SimpleClusterStateIT, ForceMergeBlocksIT, SnapshotBlocksIT, ClearIndicesCacheBlocksIT, SearchCancellationIT, SimpleRecoveryIT, RecoverAfterNodesIT, DedicatedClusterSnapshotRestoreIT, ValueCountIT, ActionNamesIT, FlushIT, StringTermsIT, InnerHitsIT, TransportSearchIT, ChildrenIT, NestedIT, GeoBoundsIT, BroadcastActionsIT, AvgIT, FullRollingRestartIT, ExplainableScriptIT, SimpleSearchIT, ZenDiscoveryIT]

The interesting logs are:

  1> [2017-04-28T16:26:26,996][INFO ][o.e.d.z.ZenDiscoveryIT   ] [testNoShardRelocationsOccurWhenElectedMasterNodeFails]: after test
  1> [2017-04-28T16:26:27,008][INFO ][o.e.d.z.ZenDiscoveryIT   ] [testDiscoveryStats]: before test
  1> [2017-04-28T16:26:27,009][INFO ][o.e.d.z.ZenDiscoveryIT   ] [ZenDiscoveryIT#testDiscoveryStats]: setting up test
  1> [2017-04-28T16:26:27,009][INFO ][o.e.t.InternalTestCluster] Setup InternalTestCluster [TEST-CHILD_VM=[1]-CLUSTER_SEED=[1301273692650131683]-HASH=[40DABCB9F1B8]-cluster] with seed [120F0D876DF8D0E3] using [0] dedicated masters, [0] (data) nodes and [0] coord only nodes (min_master_nodes are [auto-managed])
  1> [2017-04-28T16:26:27,010][DEBUG][o.e.t.InternalTestCluster] Reset test cluster with transport client ratio: [0.12804122656807682]
  1> [2017-04-28T16:26:27,010][DEBUG][o.e.t.InternalTestCluster] Cluster hasn't changed - moving out - nodes: [[]] nextNodeId: [0] numSharedNodes: [0]
  1> [2017-04-28T16:26:27,010][INFO ][o.e.d.z.ZenDiscoveryIT   ] [ZenDiscoveryIT#testDiscoveryStats]: all set up test
  1> [2017-04-28T16:26:27,011][INFO ][o.e.n.Node               ] [node_t0] initializing ...
  1> [2017-04-28T16:26:27,018][DEBUG][o.e.e.NodeEnvironment    ] [node_t0] using node location [[NodePath{path=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora/core/build/testrun/integTest/J1/temp/org.elasticsearch.discovery.zen.ZenDiscoveryIT_2A1090722DFCC931-001/tempDir-006/d0/nodes/0, spins=null}, NodePath{path=/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora/core/build/testrun/integTest/J1/temp/org.elasticsearch.discovery.zen.ZenDiscoveryIT_2A1090722DFCC931-001/tempDir-006/d1/nodes/0, spins=null}]], local_lock_id [0]
  1> [2017-04-28T16:26:27,018][DEBUG][o.e.e.NodeEnvironment    ] [node_t0] node data locations details:
  1>  -> /var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora/core/build/testrun/integTest/J1/temp/org.elasticsearch.discovery.zen.ZenDiscoveryIT_2A1090722DFCC931-001/tempDir-006/d0/nodes/0, free_space [394.9gb], usable_space [374.8gb], total_space [492gb], spins? [unknown], mount [/ (/dev/xvda1)], type [ext4]
  1>  -> /var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora/core/build/testrun/integTest/J1/temp/org.elasticsearch.discovery.zen.ZenDiscoveryIT_2A1090722DFCC931-001/tempDir-006/d1/nodes/0, free_space [394.9gb], usable_space [374.8gb], total_space [492gb], spins? [unknown], mount [/ (/dev/xvda1)], type [ext4]
  1> [2017-04-28T16:26:27,018][INFO ][o.e.e.NodeEnvironment    ] [node_t0] heap size [491mb], compressed ordinary object pointers [true]
  1> [2017-04-28T16:26:27,019][INFO ][o.e.n.Node               ] [node_t0] node name [node_t0], node ID [lGfNwWylQmaA0LYkUgLDSA]
  1> [2017-04-28T16:26:27,019][INFO ][o.e.n.Node               ] [node_t0] version[6.0.0-alpha1-SNAPSHOT], pid[12714], build[Unknown/Unknown], OS[Linux/4.8.6-300.fc25.x86_64/amd64], JVM[Oracle Corporation/OpenJDK 64-Bit Server VM/1.8.0_131/25.131-b12]
  1> [2017-04-28T16:26:27,020][WARN ][o.e.n.Node               ] [node_t0] version [6.0.0-alpha1-SNAPSHOT] is a pre-release version of Elasticsearch and is not suitable for production
  1> [2017-04-28T16:26:27,020][DEBUG][o.e.n.Node               ] [node_t0] using config [/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora/core/build/testrun/integTest/J1/temp/org.elasticsearch.discovery.zen.ZenDiscoveryIT_2A1090722DFCC931-001/tempDir-006/config], data [[/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora/core/build/testrun/integTest/J1/temp/org.elasticsearch.discovery.zen.ZenDiscoveryIT_2A1090722DFCC931-001/tempDir-006/d0, /var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora/core/build/testrun/integTest/J1/temp/org.elasticsearch.discovery.zen.ZenDiscoveryIT_2A1090722DFCC931-001/tempDir-006/d1]], logs [/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora/core/build/testrun/integTest/J1/temp/org.elasticsearch.discovery.zen.ZenDiscoveryIT_2A1090722DFCC931-001/tempDir-006/logs], plugins [/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora/core/build/testrun/integTest/J1/temp/org.elasticsearch.discovery.zen.ZenDiscoveryIT_2A1090722DFCC931-001/tempDir-006/plugins]
  1> [2017-04-28T16:26:27,020][DEBUG][o.e.p.PluginsService     ] [/var/lib/jenkins/workspace/elastic+elasticsearch+master+multijob-unix-compatibility/os/fedora/core/build/testrun/integTest/J1/temp/org.elasticsearch.discovery.zen.ZenDiscoveryIT_2A1090722DFCC931-001/tempDir-006/plugins] directory does not exist.
  1> [2017-04-28T16:26:27,020][INFO ][o.e.p.PluginsService     ] [node_t0] no modules loaded
  1> [2017-04-28T16:26:27,020][INFO ][o.e.p.PluginsService     ] [node_t0] loaded plugin [org.elasticsearch.test.ESIntegTestCase$TestSeedPlugin]
  1> [2017-04-28T16:26:27,020][INFO ][o.e.p.PluginsService     ] [node_t0] loaded plugin [org.elasticsearch.test.discovery.TestZenDiscovery$TestPlugin]
  1> [2017-04-28T16:26:27,020][INFO ][o.e.p.PluginsService     ] [node_t0] loaded plugin [org.elasticsearch.transport.MockTcpTransportPlugin]
  1> [2017-04-28T16:26:27,021][DEBUG][o.e.t.ThreadPool         ] [node_t0] created thread pool: name [force_merge], size [1], queue size [unbounded]
  1> [2017-04-28T16:26:27,021][DEBUG][o.e.t.ThreadPool         ] [node_t0] created thread pool: name [fetch_shard_started], core [1], max [2], keep alive [5m]
  1> [2017-04-28T16:26:27,021][DEBUG][o.e.t.ThreadPool         ] [node_t0] created thread pool: name [listener], size [1], queue size [unbounded]
  1> [2017-04-28T16:26:27,021][DEBUG][o.e.t.ThreadPool         ] [node_t0] created thread pool: name [index], size [1], queue size [200]
  1> [2017-04-28T16:26:27,021][DEBUG][o.e.t.ThreadPool         ] [node_t0] created thread pool: name [refresh], core [1], max [1], keep alive [5m]
  1> [2017-04-28T16:26:27,027][DEBUG][o.e.t.ThreadPool         ] [node_t0] created thread pool: name [generic], core [4], max [128], keep alive [30s]
  1> [2017-04-28T16:26:27,027][DEBUG][o.e.t.ThreadPool         ] [node_t0] created thread pool: name [warmer], core [1], max [1], keep alive [5m]
  1> [2017-04-28T16:26:27,027][DEBUG][o.e.t.ThreadPool         ] [node_t0] created thread pool: name [search], size [2], queue size [1k]
  1> [2017-04-28T16:26:27,027][DEBUG][o.e.t.ThreadPool         ] [node_t0] created thread pool: name [flush], core [1], max [1], keep alive [5m]
  1> [2017-04-28T16:26:27,027][DEBUG][o.e.t.ThreadPool         ] [node_t0] created thread pool: name [fetch_shard_store], core [1], max [2], keep alive [5m]
  1> [2017-04-28T16:26:27,027][DEBUG][o.e.t.ThreadPool         ] [node_t0] created thread pool: name [management], core [1], max [5], keep alive [5m]
  1> [2017-04-28T16:26:27,027][DEBUG][o.e.t.ThreadPool         ] [node_t0] created thread pool: name [get], size [1], queue size [1k]
  1> [2017-04-28T16:26:27,027][DEBUG][o.e.t.ThreadPool         ] [node_t0] created thread pool: name [bulk], size [1], queue size [200]
  1> [2017-04-28T16:26:27,027][DEBUG][o.e.t.ThreadPool         ] [node_t0] created thread pool: name [snapshot], core [1], max [1], keep alive [5m]
  1> [2017-04-28T16:26:27,034][DEBUG][o.e.s.ScriptService      ] [node_t0] using script cache with max_size [538], expire [26m]
  1> [2017-04-28T16:26:27,038][DEBUG][o.e.m.j.JvmGcMonitorService] [node_t0] enabled [true], interval [1s], gc_threshold [{default=GcThreshold{name='default', warnThreshold=10000, infoThreshold=5000, debugThreshold=2000}, young=GcThreshold{name='young', warnThreshold=1000, infoThreshold=700, debugThreshold=400}, old=GcThreshold{name='old', warnThreshold=10000, infoThreshold=5000, debugThreshold=2000}}], overhead [50, 25, 10]
  1> [2017-04-28T16:26:27,040][DEBUG][o.e.m.o.OsService        ] [node_t0] using refresh_interval [1s]
  1> [2017-04-28T16:26:27,040][DEBUG][o.e.m.p.ProcessService   ] [node_t0] using refresh_interval [1s]
  1> [2017-04-28T16:26:27,042][DEBUG][o.e.m.j.JvmService       ] [node_t0] using refresh_interval [1s]
  1> [2017-04-28T16:26:27,042][DEBUG][o.e.m.f.FsService        ] [node_t0] using refresh_interval [1s]
  1> [2017-04-28T16:26:27,047][DEBUG][o.e.c.r.a.d.ClusterRebalanceAllocationDecider] [node_t0] using [cluster.routing.allocation.allow_rebalance] with [indices_all_active]
  1> [2017-04-28T16:26:27,047][DEBUG][o.e.c.r.a.d.ConcurrentRebalanceAllocationDecider] [node_t0] using [cluster_concurrent_rebalance] with [2]
  1> [2017-04-28T16:26:27,050][DEBUG][o.e.c.r.a.d.ThrottlingAllocationDecider] [node_t0] using node_concurrent_outgoing_recoveries [5], node_concurrent_incoming_recoveries [5], node_initial_primaries_recoveries [4]
  1> [2017-04-28T16:26:27,055][DEBUG][o.e.i.IndicesQueryCache  ] [node_t0] using [node] query cache with size [49mb] max filter count [10000]
  1> [2017-04-28T16:26:27,055][DEBUG][o.e.i.IndexingMemoryController] [node_t0] using indexing buffer size [49mb] with indices.memory.shard_inactive_time [5m], indices.memory.interval [5s]
  1> [2017-04-28T16:26:27,057][INFO ][o.e.d.DiscoveryModule    ] [node_t0] using discovery type [test-zen]
  1> [2017-04-28T16:26:27,057][DEBUG][o.e.d.z.ElectMasterService] [node_t0] using minimum_master_nodes [1]
  1> [2017-04-28T16:26:27,058][DEBUG][o.e.t.d.TestZenDiscovery ] [node_t0] using ping_timeout [3s], join.timeout [1m], master_election.ignore_non_master [false]
  1> [2017-04-28T16:26:27,058][DEBUG][o.e.d.z.MasterFaultDetection] [node_t0] [master] uses ping_interval [1s], ping_timeout [30s], ping_retries [3]
  1> [2017-04-28T16:26:27,058][DEBUG][o.e.d.z.NodesFaultDetection] [node_t0] [node  ] uses ping_interval [1s], ping_timeout [30s], ping_retries [3]
  1> [2017-04-28T16:26:27,162][DEBUG][o.e.i.r.RecoverySettings ] [node_t0] using max_bytes_per_sec[168mb]
  1> [2017-04-28T16:26:27,214][DEBUG][o.e.g.GatewayMetaState   ] [node_t0] took 0s to load state
  1> [2017-04-28T16:26:27,215][INFO ][o.e.n.Node               ] [node_t0] initialized
  1> [2017-04-28T16:26:27,215][INFO ][o.e.n.Node               ] [node_t0] starting ...
  1> [2017-04-28T16:26:27,216][DEBUG][o.e.t.MockTcpTransport   ] [node_t0] binding server bootstrap to: [::1, 127.0.0.1]
  1> [2017-04-28T16:26:27,216][DEBUG][o.e.t.MockTcpTransport   ] [node_t0] Bound profile [default] to address {[::1]:9500}
  1> [2017-04-28T16:26:27,217][DEBUG][o.e.t.MockTcpTransport   ] [node_t0] Bound profile [default] to address {127.0.0.1:9500}
  1> [2017-04-28T16:26:27,217][INFO ][o.e.t.TransportService   ] [node_t0] publish_address {127.0.0.1:9500}, bound_addresses {[::1]:9500}, {127.0.0.1:9500}
  1> [2017-04-28T16:26:27,218][DEBUG][o.e.n.Node               ] [node_t0] waiting to join the cluster. timeout [30s]
  1> [2017-04-28T16:26:27,218][INFO ][o.e.t.d.MockZenPing      ] [node_t0] pinging using mock zen ping
  1> [2017-04-28T16:26:27,218][DEBUG][o.e.t.d.TestZenDiscovery ] [node_t0] filtered ping responses: (ignore_non_masters [false])
  1>    --> ping_response{node [{node_t0}{lGfNwWylQmaA0LYkUgLDSA}{f939e9V1Sv6hesN6ao7VOA}{127.0.0.1}{127.0.0.1:9500}], id[743], master [null],cluster_state_version [-1], cluster_name[TEST-CHILD_VM=[1]-CLUSTER_SEED=[1301273692650131683]-HASH=[40DABCB9F1B8]-cluster]}
  1> [2017-04-28T16:26:27,218][DEBUG][o.e.t.d.TestZenDiscovery ] [node_t0] elected as master, waiting for incoming joins ([0] needed)
  1> [2017-04-28T16:26:27,218][DEBUG][o.e.c.s.MasterService    ] [node_t0] processing [zen-disco-elected-as-master ([0] nodes joined)]: execute
  1> [2017-04-28T16:26:27,219][DEBUG][o.e.c.s.MasterService    ] [node_t0] cluster state updated, version [1], source [zen-disco-elected-as-master ([0] nodes joined)]
  1> [2017-04-28T16:26:27,219][INFO ][o.e.c.s.MasterService    ] [node_t0] zen-disco-elected-as-master ([0] nodes joined), reason: new_master {node_t0}{lGfNwWylQmaA0LYkUgLDSA}{f939e9V1Sv6hesN6ao7VOA}{127.0.0.1}{127.0.0.1:9500}
  1> [2017-04-28T16:26:27,219][DEBUG][o.e.c.s.MasterService    ] [node_t0] publishing cluster state version [1]
  1> [2017-04-28T16:26:27,219][DEBUG][o.e.t.d.TestZenDiscovery ] [node_t0] got first state from fresh master [lGfNwWylQmaA0LYkUgLDSA]
  1> [2017-04-28T16:26:27,219][DEBUG][o.e.c.s.ClusterApplierService] [node_t0] processing [apply cluster state (from master [master {node_t0}{lGfNwWylQmaA0LYkUgLDSA}{f939e9V1Sv6hesN6ao7VOA}{127.0.0.1}{127.0.0.1:9500} committed version [1] source [zen-disco-elected-as-master ([0] nodes joined)]])]: execute
  1> [2017-04-28T16:26:27,219][DEBUG][o.e.c.s.ClusterApplierService] [node_t0] cluster state updated, version [1], source [apply cluster state (from master [master {node_t0}{lGfNwWylQmaA0LYkUgLDSA}{f939e9V1Sv6hesN6ao7VOA}{127.0.0.1}{127.0.0.1:9500} committed version [1] source [zen-disco-elected-as-master ([0] nodes joined)]])]
  1> [2017-04-28T16:26:27,219][INFO ][o.e.c.s.ClusterApplierService] [node_t0] new_master {node_t0}{lGfNwWylQmaA0LYkUgLDSA}{f939e9V1Sv6hesN6ao7VOA}{127.0.0.1}{127.0.0.1:9500}, reason: apply cluster state (from master [master {node_t0}{lGfNwWylQmaA0LYkUgLDSA}{f939e9V1Sv6hesN6ao7VOA}{127.0.0.1}{127.0.0.1:9500} committed version [1] source [zen-disco-elected-as-master ([0] nodes joined)]])
  1> [2017-04-28T16:26:27,219][DEBUG][o.e.c.s.ClusterApplierService] [node_t0] applying cluster state version 1
  1> [2017-04-28T16:26:27,219][DEBUG][o.e.c.s.ClusterApplierService] [node_t0] apply cluster state with version 1
  1> [2017-04-28T16:26:27,219][DEBUG][o.e.c.s.ClusterApplierService] [node_t0] set locally applied cluster state to version 1
  1> [2017-04-28T16:26:27,220][DEBUG][o.e.c.s.ClusterApplierService] [node_t0] processing [apply cluster state (from master [master {node_t0}{lGfNwWylQmaA0LYkUgLDSA}{f939e9V1Sv6hesN6ao7VOA}{127.0.0.1}{127.0.0.1:9500} committed version [1] source [zen-disco-elected-as-master ([0] nodes joined)]])]: took [0s] done applying updated cluster state (version: 1, uuid: 5p2_X7AQS-KyIYdlshvh4w)
  1> [2017-04-28T16:26:27,220][INFO ][o.e.n.Node               ] [node_t0] started
  1> [2017-04-28T16:26:27,220][DEBUG][o.e.c.s.MasterService    ] [node_t0] processing [zen-disco-elected-as-master ([0] nodes joined)]: took [1ms] done publishing updated cluster state (version: 1, uuid: 5p2_X7AQS-KyIYdlshvh4w)
  1> [2017-04-28T16:26:27,220][DEBUG][o.e.c.s.MasterService    ] [node_t0] processing [cluster_health (wait_for_events [LANGUID])]: execute
  1> [2017-04-28T16:26:27,220][DEBUG][o.e.c.s.MasterService    ] [node_t0] processing [cluster_health (wait_for_events [LANGUID])]: took [0s] no change in cluster state
  1> [2017-04-28T16:26:27,221][DEBUG][o.e.c.s.MasterService    ] [node_t0] processing [local-gateway-elected-state]: execute
  1> [2017-04-28T16:26:27,222][DEBUG][o.e.c.s.MasterService    ] [node_t0] cluster state updated, version [2], source [local-gateway-elected-state]
  1> [2017-04-28T16:26:27,222][DEBUG][o.e.c.s.MasterService    ] [node_t0] publishing cluster state version [2]
  1> [2017-04-28T16:26:27,222][DEBUG][o.e.c.s.ClusterApplierService] [node_t0] processing [apply cluster state (from master [master {node_t0}{lGfNwWylQmaA0LYkUgLDSA}{f939e9V1Sv6hesN6ao7VOA}{127.0.0.1}{127.0.0.1:9500} committed version [2] source [local-gateway-elected-state]])]: execute
  1> [2017-04-28T16:26:27,222][DEBUG][o.e.c.s.ClusterApplierService] [node_t0] cluster state updated, version [2], source [apply cluster state (from master [master {node_t0}{lGfNwWylQmaA0LYkUgLDSA}{f939e9V1Sv6hesN6ao7VOA}{127.0.0.1}{127.0.0.1:9500} committed version [2] source [local-gateway-elected-state]])]
  1> [2017-04-28T16:26:27,222][DEBUG][o.e.c.s.ClusterApplierService] [node_t0] applying cluster state version 2
  1> [2017-04-28T16:26:27,222][DEBUG][o.e.c.s.ClusterApplierService] [node_t0] apply cluster state with version 2
  1> [2017-04-28T16:26:27,224][DEBUG][o.e.c.s.ClusterApplierService] [node_t0] set locally applied cluster state to version 2
  1> [2017-04-28T16:26:27,225][DEBUG][o.e.d.z.ZenDiscoveryIT   ] indices [_all] are green
  1> [2017-04-28T16:26:27,225][INFO ][o.e.d.z.ZenDiscoveryIT   ] --> request node discovery stats
  1> [2017-04-28T16:26:27,227][INFO ][o.e.d.z.ZenDiscoveryIT   ] [ZenDiscoveryIT#testDiscoveryStats]: cleaning up after test
  1> [2017-04-28T16:26:27,228][DEBUG][o.e.c.s.ClusterApplierService] [node_t0] processing [apply cluster state (from master [master {node_t0}{lGfNwWylQmaA0LYkUgLDSA}{f939e9V1Sv6hesN6ao7VOA}{127.0.0.1}{127.0.0.1:9500} committed version [2] source [local-gateway-elected-state]])]: took [6ms] done applying updated cluster state (version: 2, uuid: X8-7JG9RRSqBtD4BMrabtg)
  1> [2017-04-28T16:26:27,228][INFO ][o.e.g.GatewayService     ] [node_t0] recovered [0] indices into cluster_state
  1> [2017-04-28T16:26:27,228][DEBUG][o.e.c.s.MasterService    ] [node_t0] processing [local-gateway-elected-state]: took [6ms] done publishing updated cluster state (version: 2, uuid: X8-7JG9RRSqBtD4BMrabtg)
  1> [2017-04-28T16:26:27,230][DEBUG][o.e.c.s.MasterService    ] [node_t0] processing [delete_repository [*]]: execute
  1> [2017-04-28T16:26:27,230][DEBUG][o.e.c.s.MasterService    ] [node_t0] processing [delete_repository [*]]: took [0s] no change in cluster state
  1> [2017-04-28T16:26:27,230][INFO ][o.e.n.Node               ] [node_t0] stopping ...
  1> [2017-04-28T16:26:27,239][INFO ][o.e.n.Node               ] [node_t0] stopped
  1> [2017-04-28T16:26:27,239][INFO ][o.e.n.Node               ] [node_t0] closing ...
  1> [2017-04-28T16:26:27,240][INFO ][o.e.n.Node               ] [node_t0] closed
  1> [2017-04-28T16:26:27,240][INFO ][o.e.d.z.ZenDiscoveryIT   ] [ZenDiscoveryIT#testDiscoveryStats]: cleaned up after test
  1> [2017-04-28T16:26:27,240][INFO ][o.e.d.z.ZenDiscoveryIT   ] [testDiscoveryStats]: after test
FAILURE 0.26s J1 | ZenDiscoveryIT.testDiscoveryStats <<< FAILURES!
   > Throwable #1: java.lang.AssertionError: 
   > Expected: <0>
   >      but: was <1>
   >    at __randomizedtesting.SeedInfo.seed([2A1090722DFCC931:EB996AD02F8EF67A]:0)
   >    at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
   >    at org.elasticsearch.discovery.zen.ZenDiscoveryIT.testDiscoveryStats(ZenDiscoveryIT.java:271)
   >    at java.lang.Thread.run(Thread.java:748)

My theory is that some action from the last test leaked into this test.

ywelsch commented 7 years ago

The test complains that there is still a cluster state in the pending queue after successful return of ensureGreen. The reason is the following:

I've pushed 86aab98fde