Add missing index name to search slow log.

This commits adds the index name as part of the logging message.
Closes #17025
This commit is contained in:
Jim Ferenczi 2016-04-18 12:13:10 +02:00
parent b84a192884
commit 3dc21e780b
2 changed files with 131 additions and 13 deletions

View File

@ -33,7 +33,7 @@ import java.util.concurrent.TimeUnit;
/** /**
*/ */
public final class SearchSlowLog implements SearchOperationListener { public final class SearchSlowLog implements SearchOperationListener {
private final Index index;
private boolean reformat; private boolean reformat;
private long queryWarnThreshold; private long queryWarnThreshold;
@ -87,6 +87,8 @@ public final class SearchSlowLog implements SearchOperationListener {
this.queryLogger = Loggers.getLogger(INDEX_SEARCH_SLOWLOG_PREFIX + ".query"); this.queryLogger = Loggers.getLogger(INDEX_SEARCH_SLOWLOG_PREFIX + ".query");
this.fetchLogger = Loggers.getLogger(INDEX_SEARCH_SLOWLOG_PREFIX + ".fetch"); this.fetchLogger = Loggers.getLogger(INDEX_SEARCH_SLOWLOG_PREFIX + ".fetch");
this.index = indexSettings.getIndex();
indexSettings.getScopedSettings().addSettingsUpdateConsumer(INDEX_SEARCH_SLOWLOG_REFORMAT, this::setReformat); indexSettings.getScopedSettings().addSettingsUpdateConsumer(INDEX_SEARCH_SLOWLOG_REFORMAT, this::setReformat);
this.reformat = indexSettings.getValue(INDEX_SEARCH_SLOWLOG_REFORMAT); this.reformat = indexSettings.getValue(INDEX_SEARCH_SLOWLOG_REFORMAT);
@ -120,36 +122,38 @@ public final class SearchSlowLog implements SearchOperationListener {
@Override @Override
public void onQueryPhase(SearchContext context, long tookInNanos) { public void onQueryPhase(SearchContext context, long tookInNanos) {
if (queryWarnThreshold >= 0 && tookInNanos > queryWarnThreshold) { if (queryWarnThreshold >= 0 && tookInNanos > queryWarnThreshold) {
queryLogger.warn("{}", new SlowLogSearchContextPrinter(context, tookInNanos, reformat)); queryLogger.warn("{}", new SlowLogSearchContextPrinter(index, context, tookInNanos, reformat));
} else if (queryInfoThreshold >= 0 && tookInNanos > queryInfoThreshold) { } else if (queryInfoThreshold >= 0 && tookInNanos > queryInfoThreshold) {
queryLogger.info("{}", new SlowLogSearchContextPrinter(context, tookInNanos, reformat)); queryLogger.info("{}", new SlowLogSearchContextPrinter(index, context, tookInNanos, reformat));
} else if (queryDebugThreshold >= 0 && tookInNanos > queryDebugThreshold) { } else if (queryDebugThreshold >= 0 && tookInNanos > queryDebugThreshold) {
queryLogger.debug("{}", new SlowLogSearchContextPrinter(context, tookInNanos, reformat)); queryLogger.debug("{}", new SlowLogSearchContextPrinter(index, context, tookInNanos, reformat));
} else if (queryTraceThreshold >= 0 && tookInNanos > queryTraceThreshold) { } else if (queryTraceThreshold >= 0 && tookInNanos > queryTraceThreshold) {
queryLogger.trace("{}", new SlowLogSearchContextPrinter(context, tookInNanos, reformat)); queryLogger.trace("{}", new SlowLogSearchContextPrinter(index, context, tookInNanos, reformat));
} }
} }
@Override @Override
public void onFetchPhase(SearchContext context, long tookInNanos) { public void onFetchPhase(SearchContext context, long tookInNanos) {
if (fetchWarnThreshold >= 0 && tookInNanos > fetchWarnThreshold) { if (fetchWarnThreshold >= 0 && tookInNanos > fetchWarnThreshold) {
fetchLogger.warn("{}", new SlowLogSearchContextPrinter(context, tookInNanos, reformat)); fetchLogger.warn("{}", new SlowLogSearchContextPrinter(index, context, tookInNanos, reformat));
} else if (fetchInfoThreshold >= 0 && tookInNanos > fetchInfoThreshold) { } else if (fetchInfoThreshold >= 0 && tookInNanos > fetchInfoThreshold) {
fetchLogger.info("{}", new SlowLogSearchContextPrinter(context, tookInNanos, reformat)); fetchLogger.info("{}", new SlowLogSearchContextPrinter(index, context, tookInNanos, reformat));
} else if (fetchDebugThreshold >= 0 && tookInNanos > fetchDebugThreshold) { } else if (fetchDebugThreshold >= 0 && tookInNanos > fetchDebugThreshold) {
fetchLogger.debug("{}", new SlowLogSearchContextPrinter(context, tookInNanos, reformat)); fetchLogger.debug("{}", new SlowLogSearchContextPrinter(index, context, tookInNanos, reformat));
} else if (fetchTraceThreshold >= 0 && tookInNanos > fetchTraceThreshold) { } else if (fetchTraceThreshold >= 0 && tookInNanos > fetchTraceThreshold) {
fetchLogger.trace("{}", new SlowLogSearchContextPrinter(context, tookInNanos, reformat)); fetchLogger.trace("{}", new SlowLogSearchContextPrinter(index, context, tookInNanos, reformat));
} }
} }
private static class SlowLogSearchContextPrinter { static final class SlowLogSearchContextPrinter {
private final SearchContext context; private final SearchContext context;
private final Index index;
private final long tookInNanos; private final long tookInNanos;
private final boolean reformat; private final boolean reformat;
public SlowLogSearchContextPrinter(SearchContext context, long tookInNanos, boolean reformat) { public SlowLogSearchContextPrinter(Index index, SearchContext context, long tookInNanos, boolean reformat) {
this.context = context; this.context = context;
this.index = index;
this.tookInNanos = tookInNanos; this.tookInNanos = tookInNanos;
this.reformat = reformat; this.reformat = reformat;
} }
@ -157,6 +161,7 @@ public final class SearchSlowLog implements SearchOperationListener {
@Override @Override
public String toString() { public String toString() {
StringBuilder sb = new StringBuilder(); StringBuilder sb = new StringBuilder();
sb.append(index).append(" ");
sb.append("took[").append(TimeValue.timeValueNanos(tookInNanos)).append("], took_millis[").append(TimeUnit.NANOSECONDS.toMillis(tookInNanos)).append("], "); sb.append("took[").append(TimeValue.timeValueNanos(tookInNanos)).append("], took_millis[").append(TimeUnit.NANOSECONDS.toMillis(tookInNanos)).append("], ");
if (context.getQueryShardContext().getTypes() == null) { if (context.getQueryShardContext().getTypes() == null) {
sb.append("types[], "); sb.append("types[], ");

View File

@ -20,13 +20,126 @@
package org.elasticsearch.index; package org.elasticsearch.index;
import org.elasticsearch.Version; import org.elasticsearch.Version;
import org.elasticsearch.action.search.SearchType;
import org.elasticsearch.cache.recycler.PageCacheRecycler;
import org.elasticsearch.cluster.metadata.IndexMetaData; import org.elasticsearch.cluster.metadata.IndexMetaData;
import org.elasticsearch.common.bytes.BytesReference;
import org.elasticsearch.common.settings.Settings; import org.elasticsearch.common.settings.Settings;
import org.elasticsearch.common.unit.TimeValue; import org.elasticsearch.common.unit.TimeValue;
import org.elasticsearch.test.ESTestCase; import org.elasticsearch.common.util.BigArrays;
import org.elasticsearch.index.query.QueryShardContext;
import org.elasticsearch.index.shard.ShardId;
import org.elasticsearch.script.ScriptService;
import org.elasticsearch.script.Template;
import org.elasticsearch.search.Scroll;
import org.elasticsearch.search.builder.SearchSourceBuilder;
import org.elasticsearch.search.internal.SearchContext;
import org.elasticsearch.search.internal.ShardSearchRequest;
import org.elasticsearch.test.ESSingleNodeTestCase;
import org.elasticsearch.test.TestSearchContext;
import org.elasticsearch.threadpool.ThreadPool;
import java.io.IOException;
import static org.hamcrest.Matchers.startsWith;
public class SearchSlowLogTests extends ESTestCase { public class SearchSlowLogTests extends ESSingleNodeTestCase {
@Override
protected SearchContext createSearchContext(IndexService indexService) {
BigArrays bigArrays = indexService.getBigArrays();
ThreadPool threadPool = indexService.getThreadPool();
PageCacheRecycler pageCacheRecycler = node().injector().getInstance(PageCacheRecycler.class);
ScriptService scriptService = node().injector().getInstance(ScriptService.class);
return new TestSearchContext(threadPool, pageCacheRecycler, bigArrays, scriptService, indexService) {
@Override
public ShardSearchRequest request() {
return new ShardSearchRequest() {
@Override
public ShardId shardId() {
return null;
}
@Override
public String[] types() {
return new String[0];
}
@Override
public SearchSourceBuilder source() {
return null;
}
@Override
public void source(SearchSourceBuilder source) {
}
@Override
public int numberOfShards() {
return 0;
}
@Override
public SearchType searchType() {
return null;
}
@Override
public String[] filteringAliases() {
return new String[0];
}
@Override
public long nowInMillis() {
return 0;
}
@Override
public Template template() {
return null;
}
@Override
public Boolean requestCache() {
return null;
}
@Override
public Scroll scroll() {
return null;
}
@Override
public void setProfile(boolean profile) {
}
@Override
public boolean isProfile() {
return false;
}
@Override
public BytesReference cacheKey() throws IOException {
return null;
}
@Override
public void rewrite(QueryShardContext context) throws IOException {
}
};
}
};
}
public void testSlowLogSearchContextPrinterToLog() throws IOException {
IndexService index = createIndex("foo");
// Turning off document logging doesn't log source[]
SearchContext searchContext = createSearchContext(index);
SearchSlowLog.SlowLogSearchContextPrinter p = new SearchSlowLog.SlowLogSearchContextPrinter(index.index(), searchContext, 10, true);
assertThat(p.toString(), startsWith(index.index().toString()));
}
public void testReformatSetting() { public void testReformatSetting() {
IndexMetaData metaData = newIndexMeta("index", Settings.builder() IndexMetaData metaData = newIndexMeta("index", Settings.builder()