Test: switch to TRACE logging for some components

This commit is contained in:
Michael McCandless 2014-11-10 16:27:34 -05:00 committed by mikemccand
parent 59117125b4
commit 91bef2e40f
1 changed files with 47 additions and 38 deletions

View File

@ -36,6 +36,7 @@ import org.elasticsearch.cluster.metadata.IndexMetaData;
import org.elasticsearch.common.bytes.BytesReference; import org.elasticsearch.common.bytes.BytesReference;
import org.elasticsearch.common.io.stream.BytesStreamInput; import org.elasticsearch.common.io.stream.BytesStreamInput;
import org.elasticsearch.common.io.stream.BytesStreamOutput; import org.elasticsearch.common.io.stream.BytesStreamOutput;
import org.elasticsearch.common.logging.Loggers;
import org.elasticsearch.common.settings.ImmutableSettings; import org.elasticsearch.common.settings.ImmutableSettings;
import org.elasticsearch.common.settings.Settings; import org.elasticsearch.common.settings.Settings;
import org.elasticsearch.index.merge.policy.TieredMergePolicyProvider; import org.elasticsearch.index.merge.policy.TieredMergePolicyProvider;
@ -330,48 +331,56 @@ public class IndexStatsTests extends ElasticsearchIntegrationTest {
@Test @Test
public void throttleStats() throws Exception { public void throttleStats() throws Exception {
assertAcked(prepareCreate("test") Loggers.getLogger("lucene.iw").setLevel("TRACE");
.setSettings(ImmutableSettings.builder() Loggers.getLogger("index.merge.scheduler").setLevel("TRACE");
.put(AbstractIndexStore.INDEX_STORE_THROTTLE_TYPE, "merge") Loggers.getLogger("index.shard.service").setLevel("TRACE");
.put(IndexMetaData.SETTING_NUMBER_OF_SHARDS, "1") Loggers.getLogger("test.engine").setLevel("TRACE");
.put(IndexMetaData.SETTING_NUMBER_OF_REPLICAS, "0")
.put(TieredMergePolicyProvider.INDEX_MERGE_POLICY_MAX_MERGE_AT_ONCE, "2")
.put(TieredMergePolicyProvider.INDEX_MERGE_POLICY_SEGMENTS_PER_TIER, "2")
.put(ConcurrentMergeSchedulerProvider.MAX_THREAD_COUNT, "1")
.put(ConcurrentMergeSchedulerProvider.MAX_MERGE_COUNT, "1")
.put("index.merge.policy.type", "tiered")
)); try {
ensureGreen(); assertAcked(prepareCreate("test")
long termUpto = 0; .setSettings(ImmutableSettings.builder()
IndicesStatsResponse stats; .put(AbstractIndexStore.INDEX_STORE_THROTTLE_TYPE, "merge")
// make sure we see throttling kicking in: .put(IndexMetaData.SETTING_NUMBER_OF_SHARDS, "1")
boolean done = false; .put(IndexMetaData.SETTING_NUMBER_OF_REPLICAS, "0")
long start = System.currentTimeMillis(); .put(TieredMergePolicyProvider.INDEX_MERGE_POLICY_MAX_MERGE_AT_ONCE, "2")
while (!done) { .put(TieredMergePolicyProvider.INDEX_MERGE_POLICY_SEGMENTS_PER_TIER, "2")
for(int i=0; i<100; i++) { .put(ConcurrentMergeSchedulerProvider.MAX_THREAD_COUNT, "1")
// Provoke slowish merging by making many unique terms: .put(ConcurrentMergeSchedulerProvider.MAX_MERGE_COUNT, "1")
StringBuilder sb = new StringBuilder(); .put("index.merge.policy.type", "tiered")
for(int j=0; j<100; j++) {
sb.append(' '); ));
sb.append(termUpto++); ensureGreen();
long termUpto = 0;
IndicesStatsResponse stats;
// make sure we see throttling kicking in:
boolean done = false;
long start = System.currentTimeMillis();
while (!done) {
for(int i=0; i<100; i++) {
// Provoke slowish merging by making many unique terms:
StringBuilder sb = new StringBuilder();
for(int j=0; j<100; j++) {
sb.append(' ');
sb.append(termUpto++);
}
client().prepareIndex("test", "type", ""+termUpto).setSource("field" + (i%10), sb.toString()).get();
if (i % 2 == 0) {
refresh();
}
} }
client().prepareIndex("test", "type", ""+termUpto).setSource("field" + (i%10), sb.toString()).get(); refresh();
if (i % 2 == 0) { stats = client().admin().indices().prepareStats().execute().actionGet();
refresh(); //nodesStats = client().admin().cluster().prepareNodesStats().setIndices(true).get();
done = stats.getPrimaries().getIndexing().getTotal().getThrottleTimeInMillis() > 0;
if (System.currentTimeMillis() - start > 300*1000) { //Wait 5 minutes for throttling to kick in
fail("index throttling didn't kick in after 5 minutes of intense merging");
} }
} }
refresh(); } finally {
stats = client().admin().indices().prepareStats().execute().actionGet(); Loggers.getLogger("lucene.iw").setLevel("DEBUG");
//nodesStats = client().admin().cluster().prepareNodesStats().setIndices(true).get(); Loggers.getLogger("index.merge.scheduler").setLevel("DEBUG");
done = stats.getPrimaries().getIndexing().getTotal().getThrottleTimeInMillis() > 0; Loggers.getLogger("index.shard.service").setLevel("DEBUG");
if (System.currentTimeMillis() - start > 300*1000) { //Wait 5 minutes for throttling to kick in Loggers.getLogger("test.engine").setLevel("DEBUG");
break;
}
}
stats = client().admin().indices().prepareStats().execute().actionGet();
if (done) {
assertThat(stats.getPrimaries().getIndexing().getTotal().getThrottleTimeInMillis(), greaterThan(0l));
} }
} }