Merge pull request #17818 from jimferenczi/search_slow_log

Add missing index name to search slow log.

core/src/main/java/org/elasticsearch/index/SearchSlowLog.java

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

core/src/test/java/org/elasticsearch/index/SearchSlowLogTests.java

@@ -20,13 +20,126 @@
 package org.elasticsearch.index;
 
 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.common.bytes.BytesReference;
 import org.elasticsearch.common.settings.Settings;
 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() {
         IndexMetaData metaData = newIndexMeta("index", Settings.builder()