Skip to content

Commit

Permalink
Give more time to AutoFollowIT tests (#51938)
Browse files Browse the repository at this point in the history 
AutoFollowIT tests are regularly failing on CI because they rely 
on how cluster state updates are processed within the integration 
clusters. We tried to limit this in #49141 by moving to latches 
instead of waiting for assertions to pass but there are still some 
places were it still need to wait for the cluster state updates to 
be processed and auto-follow stats to be updated.

This commit gives more time to assertBusy() that verifies the 
AutoFollowStats (up to 60 seconds) and also always log the 
auto-follow stats in case the assertions failed.

Closes #48982
  • Loading branch information
@tlrx
tlrx committed Feb 5, 2020
1 parent 290fb70 commit e856734
Showing 1 changed file with 56 additions and 46 deletions.
102 changes: 56 additions & 46 deletions x-pack/plugin/ccr/src/test/java/org/elasticsearch/xpack/ccr/AutoFollowIT.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -5,12 +5,14 @@
*/
package org.elasticsearch.xpack.ccr;

import org.apache.logging.log4j.message.ParameterizedMessage;
import org.elasticsearch.ElasticsearchException;
import org.elasticsearch.action.admin.indices.create.CreateIndexRequest;
import org.elasticsearch.action.admin.indices.delete.DeleteIndexRequest;
import org.elasticsearch.client.Client;
import org.elasticsearch.cluster.metadata.IndexMetaData;
import org.elasticsearch.cluster.metadata.MetaData;
import org.elasticsearch.common.CheckedRunnable;
import org.elasticsearch.common.Strings;
import org.elasticsearch.common.regex.Regex;
import org.elasticsearch.common.settings.Settings;
Expand Down Expand Up @@ -80,7 +82,7 @@ public void testAutoFollow() throws Exception {
assertTrue(ESIntegTestCase.indexExists("copy-logs-201901", followerClient()));
});
createLeaderIndex("transactions-201901", leaderIndexSettings);
assertBusy(() -> {
assertLongBusy(() -> {
AutoFollowStats autoFollowStats = getAutoFollowStats();
assertThat(autoFollowStats.getNumberOfSuccessfulFollowIndices(), equalTo(2L));
assertTrue(ESIntegTestCase.indexExists("copy-transactions-201901", followerClient()));
Expand All @@ -98,7 +100,7 @@ public void testCleanFollowedLeaderIndexUUIDs() throws Exception {

putAutoFollowPatterns("my-pattern", new String[] {"logs-*"});
createLeaderIndex("logs-201901", leaderIndexSettings);
assertBusy(() -> {
assertLongBusy(() -> {
AutoFollowStats autoFollowStats = getAutoFollowStats();
assertThat(autoFollowStats.getNumberOfSuccessfulFollowIndices(), equalTo(1L));

Expand All @@ -118,7 +120,7 @@ public void testCleanFollowedLeaderIndexUUIDs() throws Exception {
DeleteIndexRequest deleteIndexRequest = new DeleteIndexRequest("logs-201901");
assertAcked(leaderClient().admin().indices().delete(deleteIndexRequest).actionGet());

assertBusy(() -> {
assertLongBusy(() -> {
AutoFollowMetadata autoFollowMetadata = getFollowerCluster().clusterService().state()
.metaData()
.custom(AutoFollowMetadata.TYPE);
Expand All @@ -143,15 +145,15 @@ public void testAutoFollowManyIndices() throws Exception {
MetaData[] metaData = new MetaData[1];
AutoFollowStats[] autoFollowStats = new AutoFollowStats[1];
try {
assertBusy(() -> {
assertLongBusy(() -> {
metaData[0] = getFollowerCluster().clusterService().state().metaData();
autoFollowStats[0] = getAutoFollowStats();

assertThat(metaData[0].indices().size(), equalTo((int) expectedVal1));
AutoFollowMetadata autoFollowMetadata = metaData[0].custom(AutoFollowMetadata.TYPE);
assertThat(autoFollowMetadata.getFollowedLeaderIndexUUIDs().get("my-pattern"), hasSize((int) expectedVal1));
assertThat(autoFollowStats[0].getNumberOfSuccessfulFollowIndices(), equalTo(expectedVal1));
}, 30, TimeUnit.SECONDS);
});
} catch (AssertionError ae) {
logger.warn("indices={}", Arrays.toString(metaData[0].indices().keys().toArray(String.class)));
logger.warn("auto follow stats={}", Strings.toString(autoFollowStats[0]));
Expand All @@ -162,15 +164,15 @@ public void testAutoFollowManyIndices() throws Exception {
// then the leader index created after that should never be auto followed:
deleteAutoFollowPattern("my-pattern");
try {
assertBusy(() -> {
assertLongBusy(() -> {
metaData[0] = getFollowerCluster().clusterService().state().metaData();
autoFollowStats[0] = getAutoFollowStats();

assertThat(metaData[0].indices().size(), equalTo((int )expectedVal1));
AutoFollowMetadata autoFollowMetadata = metaData[0].custom(AutoFollowMetadata.TYPE);
assertThat(autoFollowMetadata.getFollowedLeaderIndexUUIDs().get("my-pattern"), nullValue());
assertThat(autoFollowStats[0].getAutoFollowedClusters().size(), equalTo(0));
}, 30, TimeUnit.SECONDS);
});
} catch (AssertionError ae) {
logger.warn("indices={}", Arrays.toString(metaData[0].indices().keys().toArray(String.class)));
logger.warn("auto follow stats={}", Strings.toString(autoFollowStats[0]));
Expand All @@ -186,27 +188,21 @@ public void testAutoFollowManyIndices() throws Exception {
}
long expectedVal2 = numIndices;

try {
assertBusy(() -> {
metaData[0] = getFollowerCluster().clusterService().state().metaData();
autoFollowStats[0] = getAutoFollowStats();

assertThat(metaData[0].indices().size(), equalTo((int) expectedVal2));
AutoFollowMetadata autoFollowMetadata = metaData[0].custom(AutoFollowMetadata.TYPE);
// expectedVal2 + 1, because logs-does-not-count is also marked as auto followed.
// (This is because indices created before a pattern exists are not auto followed and are just marked as such.)
assertThat(autoFollowMetadata.getFollowedLeaderIndexUUIDs().get("my-pattern"), hasSize((int) expectedVal2 + 1));
long count = Arrays.stream(metaData[0].getConcreteAllIndices()).filter(s -> s.startsWith("copy-")).count();
assertThat(count, equalTo(expectedVal2));
// Ensure that there are no auto follow errors:
// (added specifically to see that there are no leader indices auto followed multiple times)
assertThat(autoFollowStats[0].getRecentAutoFollowErrors().size(), equalTo(0));
}, 30, TimeUnit.SECONDS);
} catch (AssertionError ae) {
logger.warn("indices={}", Arrays.toString(metaData[0].indices().keys().toArray(String.class)));
logger.warn("auto follow stats={}", Strings.toString(autoFollowStats[0]));
throw ae;
}
assertLongBusy(() -> {
metaData[0] = getFollowerCluster().clusterService().state().metaData();
autoFollowStats[0] = getAutoFollowStats();

assertThat(metaData[0].indices().size(), equalTo((int) expectedVal2));
AutoFollowMetadata autoFollowMetadata = metaData[0].custom(AutoFollowMetadata.TYPE);
// expectedVal2 + 1, because logs-does-not-count is also marked as auto followed.
// (This is because indices created before a pattern exists are not auto followed and are just marked as such.)
assertThat(autoFollowMetadata.getFollowedLeaderIndexUUIDs().get("my-pattern"), hasSize((int) expectedVal2 + 1));
long count = Arrays.stream(metaData[0].getConcreteAllIndices()).filter(s -> s.startsWith("copy-")).count();
assertThat(count, equalTo(expectedVal2));
// Ensure that there are no auto follow errors:
// (added specifically to see that there are no leader indices auto followed multiple times)
assertThat(autoFollowStats[0].getRecentAutoFollowErrors().size(), equalTo(0));
});
}

public void testAutoFollowParameterAreDelegated() throws Exception {
Expand Down Expand Up @@ -322,7 +318,7 @@ public void testConflictingPatterns() throws Exception {
putAutoFollowPatterns("my-pattern2", new String[] {"logs-2018*"});

createLeaderIndex("logs-201701", leaderIndexSettings);
assertBusy(() -> {
assertLongBusy(() -> {
AutoFollowStats autoFollowStats = getAutoFollowStats();
assertThat(autoFollowStats.getNumberOfSuccessfulFollowIndices(), equalTo(1L));
assertThat(autoFollowStats.getNumberOfFailedFollowIndices(), equalTo(0L));
Expand All @@ -331,7 +327,7 @@ public void testConflictingPatterns() throws Exception {
assertTrue(ESIntegTestCase.indexExists("copy-logs-201701", followerClient()));

createLeaderIndex("logs-201801", leaderIndexSettings);
assertBusy(() -> {
assertLongBusy(() -> {
AutoFollowStats autoFollowStats = getAutoFollowStats();
assertThat(autoFollowStats.getNumberOfSuccessfulFollowIndices(), equalTo(1L));
assertThat(autoFollowStats.getNumberOfFailedFollowIndices(), greaterThanOrEqualTo(1L));
Expand Down Expand Up @@ -363,15 +359,15 @@ public void testPauseAndResumeAutoFollowPattern() throws Exception {

// create the auto follow pattern
putAutoFollowPatterns("test-pattern", new String[]{"test-*", "tests-*"});
assertBusy(() -> {
assertLongBusy(() -> {
final AutoFollowStats autoFollowStats = getAutoFollowStats();
assertThat(autoFollowStats.getAutoFollowedClusters().size(), equalTo(1));
assertThat(autoFollowStats.getNumberOfSuccessfulFollowIndices(), equalTo(0L));
});

// index created in the remote cluster are auto followed
createLeaderIndex("test-new-index-is-auto-followed", leaderIndexSettings);
assertBusy(() -> {
assertLongBusy(() -> {
final AutoFollowStats autoFollowStats = getAutoFollowStats();
assertThat(autoFollowStats.getAutoFollowedClusters().size(), equalTo(1));
assertThat(autoFollowStats.getNumberOfSuccessfulFollowIndices(), equalTo(1L));
Expand Down Expand Up @@ -411,10 +407,11 @@ public void testPauseAndResumeAutoFollowPattern() throws Exception {

// resume the auto follow pattern, indices created while the pattern was paused are picked up for auto-following
resumeAutoFollowPattern("test-pattern");
assertBusy(() -> {
assertLongBusy(() -> {
final Client client = followerClient();
assertThat(getAutoFollowStats().getAutoFollowedClusters().size(), equalTo(1));
assertThat(client.admin().indices().prepareStats("copy-*").get().getIndices().size(), equalTo(1 + nbIndicesCreatedWhilePaused));
assertThat(client.admin().cluster().prepareState().clear().setIndices("copy-*").setMetaData(true).get()
.getState().getMetaData().getIndices().size(), equalTo(1 + nbIndicesCreatedWhilePaused));
for (int i = 0; i < nbIndicesCreatedWhilePaused; i++) {
assertTrue(ESIntegTestCase.indexExists("copy-test-index-created-while-pattern-is-paused-" + i, client));
}
Expand Down Expand Up @@ -474,31 +471,27 @@ public void testPauseAndResumeWithMultipleAutoFollowPatterns() throws Exception
createNewLeaderIndicesThread.start();

// wait for 3 leader indices to be created on the remote cluster
latchThree.await(30L, TimeUnit.SECONDS);
latchThree.await(60L, TimeUnit.SECONDS);
assertThat(leaderIndices.get(), greaterThanOrEqualTo(3));
assertBusy(() -> assertThat(getAutoFollowStats().getNumberOfSuccessfulFollowIndices(), greaterThanOrEqualTo(3L)),
30L, TimeUnit.SECONDS);
assertLongBusy(() -> assertThat(getAutoFollowStats().getNumberOfSuccessfulFollowIndices(), greaterThanOrEqualTo(3L)));

// now pause some random patterns
pausedAutoFollowerPatterns.forEach(this::pauseAutoFollowPattern);
assertBusy(() -> autoFollowPatterns.forEach(pattern ->
assertThat(getAutoFollowPattern(pattern).isActive(), equalTo(pausedAutoFollowerPatterns.contains(pattern) == false))),
30L, TimeUnit.SECONDS);
assertLongBusy(() -> autoFollowPatterns.forEach(pattern ->
assertThat(getAutoFollowPattern(pattern).isActive(), equalTo(pausedAutoFollowerPatterns.contains(pattern) == false))));

// wait for more leader indices to be created on the remote cluster
latchSix.await(30L, TimeUnit.SECONDS);
latchSix.await(60L, TimeUnit.SECONDS);
assertThat(leaderIndices.get(), greaterThanOrEqualTo(6));

// resume auto follow patterns
pausedAutoFollowerPatterns.forEach(this::resumeAutoFollowPattern);
assertBusy(() -> autoFollowPatterns.forEach(pattern -> assertTrue(getAutoFollowPattern(pattern).isActive())),
30L, TimeUnit.SECONDS);
assertLongBusy(() -> autoFollowPatterns.forEach(pattern -> assertTrue(getAutoFollowPattern(pattern).isActive())));

// wait for more leader indices to be created on the remote cluster
latchNine.await(30L, TimeUnit.SECONDS);
latchNine.await(60L, TimeUnit.SECONDS);
assertThat(leaderIndices.get(), greaterThanOrEqualTo(9));
assertBusy(() -> assertThat(getAutoFollowStats().getNumberOfSuccessfulFollowIndices(), greaterThanOrEqualTo(9L)),
30L, TimeUnit.SECONDS);
assertLongBusy(() -> assertThat(getAutoFollowStats().getNumberOfSuccessfulFollowIndices(), greaterThanOrEqualTo(9L)));

running.set(false);
createNewLeaderIndicesThread.join();
Expand Down Expand Up @@ -563,4 +556,21 @@ private AutoFollowMetadata.AutoFollowPattern getAutoFollowPattern(final String n
assertTrue(response.getAutoFollowPatterns().containsKey(name));
return response.getAutoFollowPatterns().get(name);
}

private void assertLongBusy(CheckedRunnable<Exception> codeBlock) throws Exception {
try {
assertBusy(codeBlock, 60L, TimeUnit.SECONDS);
} catch (AssertionError ae) {
AutoFollowStats autoFollowStats = null;
try {
autoFollowStats = getAutoFollowStats();
} catch (Exception e) {
ae.addSuppressed(e);
}
final AutoFollowStats finalAutoFollowStats = autoFollowStats;
logger.warn(() -> new ParameterizedMessage("AssertionError when waiting for auto-follower, auto-follow stats are: {}",
finalAutoFollowStats != null ? Strings.toString(finalAutoFollowStats) : "null"), ae);
throw ae;
}
}
}

0 comments on commit e856734

Please sign in to comment.